diff --git a/bmspy/ups.py b/bmspy/ups.py index e70be6b..47de3e8 100644 --- a/bmspy/ups.py +++ b/bmspy/ups.py @@ -7,13 +7,15 @@ import smtplib import ssl import socket from collections import deque -from collections.abc import Collection +from collections.abc import Callable, Collection from bmspy import client from bmspy.classes import UPS, BMSScalarField DAEMON_UPDATE_PERIOD = 30 STARTUP_RETRY_PERIOD = 5 +# Report a device that sends no data for this many seconds. +DATA_LOSS_PERIOD = 300 USAGE_ERROR_STATUS = 2 scheduled_shutdown = False @@ -64,7 +66,43 @@ def _resolve_ups_device(data: Collection[str], requested: str | None) -> str | N return next(iter(data)) -def _wait_for_ups_device(socket_path: str, requested: str | None) -> str | None: +class _DataMonitor: + """Report when the device stops sending data, and when the data returns. + + One email goes out after DATA_LOSS_PERIOD seconds with no data. The next + email is the one for the return of the data, so a long failure sends one + email and not one for each read. + """ + + def __init__(self, send_email: Callable[..., None]) -> None: + self.send_email = send_email + self.last_data = time.monotonic() + self.reported = False + + def update(self, name: str, has_data: bool) -> None: + """Record the result of one read of the device *name*.""" + now = time.monotonic() + if has_data: + self.last_data = now + if self.reported: + self.reported = False + self.send_email( + text="data from UPS '{}' regained".format(name), + level="Data recovery alert", + ) + elif not self.reported and now - self.last_data >= DATA_LOSS_PERIOD: + self.reported = True + self.send_email( + text="no data from UPS '{}' for {} minutes".format( + name, DATA_LOSS_PERIOD // 60 + ), + level="Data loss alert", + ) + + +def _wait_for_ups_device( + socket_path: str, requested: str | None, data_monitor: _DataMonitor | None = None, +) -> str | None: """Select the device to monitor, then wait until the server has data for it. The selection uses the configured device names, not the devices that have @@ -76,6 +114,8 @@ def _wait_for_ups_device(socket_path: str, requested: str | None) -> str | None: return None waiting = False while name not in client.read_data(socket_path, "ups", ups=name): + if data_monitor is not None: + data_monitor.update(name, False) if not waiting: print("UPS '{}' has no data yet, waiting...".format(name)) waiting = True @@ -249,7 +289,20 @@ def main() -> None: client.handle_registration(args.socket, "ups", debug) atexit.register(client.handle_registration, args.socket, "ups", debug) - device_name = _wait_for_ups_device(args.socket, args.device) + def send_email(text: str, level: str) -> None: + handle_email( + text=text, + level=level, + recipient=args.recipient, + mailserver=args.mailserver, + port=args.port, + mailuser=args.mailuser, + mailpass=args.mailpass, + debug=debug, + ) + + data_monitor = _DataMonitor(send_email) + device_name = _wait_for_ups_device(args.socket, args.device, data_monitor) if device_name is None: # A wrong or missing --device is a usage error, as in argparse. A retry # cannot fix it, so the service file does not restart on this status. @@ -259,6 +312,7 @@ def main() -> None: while True: data = client.read_data(args.socket, "ups", ups=device_name) device_obj = data.get(device_name) + data_monitor.update(device_name, device_obj is not None) if device_obj is None: time.sleep(DAEMON_UPDATE_PERIOD) continue diff --git a/tests/test_ups.py b/tests/test_ups.py index 73acb6c..d844064 100644 --- a/tests/test_ups.py +++ b/tests/test_ups.py @@ -469,13 +469,18 @@ class TestUpsMain: def _events(self, readings, argv=None): """Run main() over (current, charge ratio) readings, 30 seconds apart. - Return (reading number, event) for each email and each shutdown call. + A reading of None is a read in which the server has no data for the + device. Return (reading number, event) for each email and each + shutdown call. """ - sequence = [self._make_data(*reading) for reading in readings] - for data, (current, _) in zip(sequence, readings): - if current is None: + sequence = [{} if reading is None else self._make_data(*reading) for reading in readings] + for data, reading in zip(sequence, readings): + if reading is not None and reading[0] is None: del data["testups"]._fields["bms_current_amps"] - events, number = [], [0] + events, number, clock = [], [0], [1000.0] + + def sleep(seconds): + clock[0] += seconds def read(*args, **kwargs): if number[0] > len(sequence): @@ -487,7 +492,8 @@ class TestUpsMain: with patch("sys.argv", ["bmspy-ups"] + (argv or [])), \ patch("bmspy.ups.client.read_data", side_effect=read), \ patch("bmspy.ups.client.handle_registration"), \ - patch("bmspy.ups.time.sleep"), \ + patch("bmspy.ups.time.sleep", side_effect=sleep), \ + patch("bmspy.ups.time.monotonic", side_effect=lambda: clock[0]), \ patch("bmspy.ups.handle_shutdown", side_effect=lambda action, **kw: events.append((number[0] - 1, action))), \ patch("bmspy.ups.handle_email", @@ -555,6 +561,34 @@ class TestUpsMain: events = self._events([(None, 0.95)] * 5 + [(None, 0.20)] * 2) assert events == [(7, "shutdown"), (7, "Critical alert")] + def test_no_data_for_five_minutes_is_reported_once_and_the_return_once(self): + """Readings are 30 seconds apart, so the tenth read with no data is at 5 minutes.""" + readings = ( + [(1.0, 0.95)] * 3 # readings 1 to 3: data + + [None] * 25 # 4 to 28: no data for 12.5 minutes + + [(1.0, 0.95)] * 3 # 29 to 31: the data returns + + [None] * 9 # 32 to 40: 4.5 minutes, below the limit + + [(1.0, 0.95)] * 2 # 41 and 42 + + [None] * 12 # 43 to 54: no data for 6 minutes + ) + assert self._events(readings) == [ + (13, "Data loss alert"), (29, "Data recovery alert"), (52, "Data loss alert"), + ] + + def test_data_loss_email_names_the_device(self): + send_email = MagicMock() + with patch("bmspy.ups.time.monotonic", side_effect=[0, 299, 300, 900, 901]): + monitor = ups_mod._DataMonitor(send_email) + monitor.update("network", False) # 299 seconds: below the limit + send_email.assert_not_called() + monitor.update("network", False) # 300 seconds + monitor.update("network", False) # no second email + monitor.update("network", True) + assert [c.kwargs for c in send_email.call_args_list] == [ + {"text": "no data from UPS 'network' for 5 minutes", "level": "Data loss alert"}, + {"text": "data from UPS 'network' regained", "level": "Data recovery alert"}, + ] + def test_main_not_enough_history_debug_2(self, capsys): """With debug=2 and < 4 readings, prints 'not enough readings'.""" data_seq = [self._make_data(0.0, 0.95)] * 5 @@ -680,6 +714,30 @@ class TestUpsMainDeviceSelection: # The reason is reported once, not on each retry. assert capsys.readouterr().out.count("UPS 'ups1' has no data yet") == 1 + def test_no_data_at_startup_for_five_minutes_is_reported(self): + """The startup wait reads every 5 seconds, so read 61 is at 5 minutes.""" + clock = [1000.0] + + def sleep(seconds): + clock[0] += seconds + + reads = [{}] * 70 + [self._make_data("ups1"), self._make_data("ups1"), StopIteration("done")] + mock_email = MagicMock() + with patch("sys.argv", ["bmspy-ups", "--to", "admin@example.com"]), \ + patch("bmspy.ups.client.list_devices", return_value=["ups1"]), \ + patch("bmspy.ups.client.read_data", side_effect=reads) as read_data, \ + patch("bmspy.ups.client.handle_registration"), \ + patch("bmspy.ups.time.sleep", side_effect=sleep), \ + patch("bmspy.ups.time.monotonic", side_effect=lambda: clock[0]), \ + patch("bmspy.ups.handle_email", mock_email): + with pytest.raises(StopIteration): + ups_mod.main() + assert [(c.kwargs["level"], c.kwargs["recipient"]) for c in mock_email.call_args_list] == [ + ("Data loss alert", "admin@example.com"), ("Data recovery alert", "admin@example.com"), + ] + # The loss email goes out during the wait, and the other one after it. + assert read_data.call_count == 73 + def test_main_selects_from_configured_devices_not_from_those_with_data(self): """One device with data must not be picked when the server has several.""" with patch("sys.argv", ["bmspy-ups", "--device", "ups2"]), \