diff --git a/openc3/lib/openc3/utilities/topic_lag_monitor.rb b/openc3/lib/openc3/utilities/topic_lag_monitor.rb index 885c54319c..78d8c88658 100644 --- a/openc3/lib/openc3/utilities/topic_lag_monitor.rb +++ b/openc3/lib/openc3/utilities/topic_lag_monitor.rb @@ -53,6 +53,7 @@ def initialize(name:, logger:, metric: nil) @max_lag = 0.0 @max_lag_topic = nil @below_since = nil + @below_ok_since = nil @last_notify = nil @last_notify_level = OK @notified = false @@ -104,6 +105,11 @@ def update_gauge(metric_name, help, lag, now) end def update_state(topic, lag, now) + if lag < @warn_seconds * CLEAR_RATIO + @below_ok_since ||= now + else + @below_ok_since = nil + end if lag > @max_lag @max_lag = lag @max_lag_topic = topic @@ -131,8 +137,9 @@ def update_state(topic, lag, now) @below_since ||= now if (now - @below_since) >= @clear_seconds @below_since = nil - if @state == CRITICAL and lag >= @warn_seconds * CLEAR_RATIO + if @state == CRITICAL and (@below_ok_since.nil? or (now - @below_ok_since) < @clear_seconds) @state = WARN + @below_since = @below_ok_since else @state = OK @logger.info("#{@name} has caught up processing (max lag #{@max_lag.round(1)}s on #{@max_lag_topic})", type: Logger::NOTIFICATION) if @notified diff --git a/openc3/python/openc3/utilities/topic_lag_monitor.py b/openc3/python/openc3/utilities/topic_lag_monitor.py index 8382acbf37..2afb5b5f7c 100644 --- a/openc3/python/openc3/utilities/topic_lag_monitor.py +++ b/openc3/python/openc3/utilities/topic_lag_monitor.py @@ -55,6 +55,7 @@ def __init__(self, name, logger, metric=None): self.max_lag = 0.0 self.max_lag_topic = None self.below_since = None + self.below_ok_since = None self.last_notify = None self.last_notify_level = self.OK self.notified = False @@ -101,6 +102,11 @@ def _update_gauge(self, metric_name, help, lag, now): self.metric.set(name=metric_name, value=value, type="gauge", unit="seconds", help=help) def _update_state(self, topic, lag, now): + if lag < self.warn_seconds * self.CLEAR_RATIO: + if self.below_ok_since is None: + self.below_ok_since = now + else: + self.below_ok_since = None if lag > self.max_lag: self.max_lag = lag self.max_lag_topic = topic @@ -130,8 +136,11 @@ def _update_state(self, topic, lag, now): self.below_since = now if (now - self.below_since) >= self.clear_seconds: self.below_since = None - if self.state == self.CRITICAL and lag >= self.warn_seconds * self.CLEAR_RATIO: + if self.state == self.CRITICAL and ( + self.below_ok_since is None or (now - self.below_ok_since) < self.clear_seconds + ): self.state = self.WARN + self.below_since = self.below_ok_since else: self.state = self.OK if self.notified: diff --git a/openc3/python/test/utilities/test_topic_lag_monitor.py b/openc3/python/test/utilities/test_topic_lag_monitor.py index cfe697f871..df8d612d3d 100644 --- a/openc3/python/test/utilities/test_topic_lag_monitor.py +++ b/openc3/python/test/utilities/test_topic_lag_monitor.py @@ -111,6 +111,19 @@ def test_steps_down_from_critical_to_warning_silently(self): self.assertEqual(monitor.state, TopicLagMonitor.WARN) self.logger.info.assert_not_called() + def test_critical_recovery_requires_hold_below_warning_clear_threshold(self): + monitor = self.monitor() + self.rec(monitor, 40, 0) + self.rec(monitor, 10, 1) + self.rec(monitor, 1, 11) + self.assertEqual(monitor.state, TopicLagMonitor.WARN) + self.logger.info.assert_not_called() + self.rec(monitor, 1, 20) + self.logger.info.assert_not_called() + self.rec(monitor, 1, 21) + self.assertEqual(monitor.state, TopicLagMonitor.OK) + self.logger.info.assert_called_once() + def test_rate_limits_repeated_notifications(self): monitor = self.monitor() self.rec(monitor, 6, 0) diff --git a/openc3/spec/utilities/topic_lag_monitor_spec.rb b/openc3/spec/utilities/topic_lag_monitor_spec.rb index 786a4c70b1..97d180ce41 100644 --- a/openc3/spec/utilities/topic_lag_monitor_spec.rb +++ b/openc3/spec/utilities/topic_lag_monitor_spec.rb @@ -90,6 +90,19 @@ def rec_gauge(lag, at) expect(monitor.state).to eq(TopicLagMonitor::WARN) end + it "requires the full hold below the warning clear threshold to recover from critical" do + rec(40, 0) + rec(10, 1) + rec(1, 11) + expect(monitor.state).to eq(TopicLagMonitor::WARN) + expect(logger).not_to have_received(:info) + rec(1, 20) + expect(logger).not_to have_received(:info) + rec(1, 21) + expect(monitor.state).to eq(TopicLagMonitor::OK) + expect(logger).to have_received(:info).once + end + it "rate limits repeated notifications while lagging" do expect(logger).to receive(:warn).twice rec(6, 0)