diff --git a/.gitignore b/.gitignore index 0a34beb..85209a7 100644 --- a/.gitignore +++ b/.gitignore @@ -9,5 +9,6 @@ eggs parts log.txt.log *.egg-info +*.tmp lib lib64 \ No newline at end of file diff --git a/lennoxs30api/__init__.py b/lennoxs30api/__init__.py index 753ae0f..7d95fe7 100644 --- a/lennoxs30api/__init__.py +++ b/lennoxs30api/__init__.py @@ -1,4 +1,4 @@ -__version__ = "0.1.8" +__version__ = "0.1.9" from .lennox_home import * from .lennox_period import * from .lennox_schedule import * diff --git a/lennoxs30api/message_logger.py b/lennoxs30api/message_logger.py index 57f2666..5826edf 100644 --- a/lennoxs30api/message_logger.py +++ b/lennoxs30api/message_logger.py @@ -10,16 +10,18 @@ def __init__( self, logger=None, enabled: bool = True, message_logging_file: str = None ): if message_logging_file != None: - self.logger = logging.getLogger(__name__) + self.loggerName = __name__ + "." + message_logging_file + self.logger = logging.getLogger(self.loggerName) self.logger.setLevel(level=logging.DEBUG) logFormatter = logging.Formatter( "%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s] %(message)s" ) - - fileHandler = logging.FileHandler(message_logging_file) - fileHandler.setFormatter(logFormatter) - fileHandler.setLevel(logging.DEBUG) - self.logger.addHandler(fileHandler) + ## If the logger already exists and has a handler to write to the file then do not add another one. + if len(self.logger.handlers) == 0: + fileHandler = logging.FileHandler(message_logging_file) + fileHandler.setFormatter(logFormatter) + fileHandler.setLevel(logging.DEBUG) + self.logger.addHandler(fileHandler) # When running in this mode, message should only appear in the message log and not also the default log. self.logger.propagate = False else: diff --git a/lennoxs30api/metrics.py b/lennoxs30api/metrics.py index be67e6a..6b6fc4b 100644 --- a/lennoxs30api/metrics.py +++ b/lennoxs30api/metrics.py @@ -27,6 +27,9 @@ def reset(self) -> None: self.last_reconnect_time: datetime = None self.last_message_time: datetime = None + self.sibling_message_drop: int = 0 + self.sender_message_drop: int = 0 + self.bytes_in: int = 0 self.bytes_out: int = 0 @@ -45,13 +48,15 @@ def getMetricList(self): "http_4xx_cnt": self.http_4xx_cnt, "http_5xx_cnt": self.http_5xx_cnt, "timeouts": self.timeouts, - "client_respone_errors": self.client_response_errors, + "client_response_errors": self.client_response_errors, "server_disconnects": self.server_disconnects, "connection_errors": self.connection_errors, "last_receive_time": self.last_receive_time, "last_error_time": self.last_error_time, "last_reconnect_time": self.last_reconnect_time, "last_message_time": self.last_message_time, + "sender_message_drop": self.sender_message_drop, + "sibling_message_drop": self.sibling_message_drop, } def inc_message_count(self) -> None: @@ -92,6 +97,12 @@ def inc_client_response_errors(self) -> None: self.client_response_errors += 1 self.last_error_time = self.now() + def inc_sibling_message_drop(self) -> None: + self.sibling_message_drop += 1 + + def inc_sender_message_drop(self) -> None: + self.sender_message_drop += 1 + def process_http_code(self, http_code: int) -> None: if http_code >= 200 and http_code <= 299: self.http_2xx_cnt += 1 diff --git a/lennoxs30api/s30api_async.py b/lennoxs30api/s30api_async.py index 97423f2..1f205d6 100644 --- a/lennoxs30api/s30api_async.py +++ b/lennoxs30api/s30api_async.py @@ -685,7 +685,20 @@ def processMessage(self, message): if system != None: system.processMessage(message) else: - _LOGGER.error("messagePump unknown SenderId/SystemId [" + str(sysId) + "]") + system: lennox_system = self.getSystemSibling(sysId) + if system == None: + self.metrics.inc_sender_message_drop() + _LOGGER.error(f"processMessage unknown SenderId/SystemId [{sysId}]") + else: + self.metrics.inc_sibling_message_drop() + if self.metrics.sibling_message_drop == 1: + _LOGGER.warning( + f"processMessage dropping message from sibling [{sysId}] for system [{system.sysId}] - please consult https://github.com/PeteRager/lennoxs30/blob/master/docs/sibling.md for configuration assistance" + ) + else: + _LOGGER.debug( + f"processMessage dropping message from sibling [{sysId}] for system [{system.sysId}]" + ) # Messages seem to use unique GUIDS, here we create one def getNewMessageID(self): @@ -758,6 +771,12 @@ def getSystem(self, sysId) -> "lennox_system": return system return None + def getSystemSibling(self, sysId: str) -> "lennox_system": + for system in self._systemList: + if system.sibling_identifier == sysId: + return system + return None + def getOrCreateSystem(self, sysId: str) -> "lennox_system": system = self.getSystem(sysId) if system != None: @@ -979,6 +998,13 @@ def __init__(self, sysId: str): self.sa_cancel: bool = None self.sa_state: str = None self.sa_setpointState: str = None + # Sibling data + self.sibling_self_identifier: str = None + self.sibling_identifier: str = None + self.sibling_systemName: str = None + self.sibling_nodePresent: str = None + self.sibling_portNumber: str = None + self.sibling_ipAddress: str = None self._dirty = False self._dirtyList = [] @@ -990,6 +1016,7 @@ def __init__(self, sysId: str): "devices": self._processDevices, "equipments": self._processEquipments, "systemControl": self._processSystemControl, + "siblings": self._processSiblings, } _LOGGER.info(f"Creating lennox_system sysId [{self.sysId}]") @@ -1052,6 +1079,24 @@ def _processSystemControl(self, systemControl): if "diagControl" in systemControl: self.attr_updater(systemControl["diagControl"], "level", "diagLevel") + def _processSiblings(self, siblings): + i = len(siblings) + if i == 0: + return + if i > 1: + _LOGGER.error( + f"Encountered system with more than one sibling, please open an issue. Message: {siblings}" + ) + # It appears there could be more than one of these, for now lets only process the first one. + sibling = siblings[0] + self.attr_updater(sibling, "selfIdentifier", "sibling_self_identifier") + if "sibling" in sibling: + self.attr_updater(sibling["sibling"], "identifier", "sibling_identifier") + self.attr_updater(sibling["sibling"], "systemName", "sibling_systemName") + self.attr_updater(sibling["sibling"], "portNumber", "sibling_portNumber") + self.attr_updater(sibling["sibling"], "nodePresent", "sibling_nodePresent") + self.attr_updater(sibling["sibling"], "ipAddress", "sibling_ipAddress") + def _processSchedules(self, schedules): """Processes the schedule messages, throws base exceptions if a problem is encoutered""" for schedule in schedules: diff --git a/setup.py b/setup.py index 66da08d..fafe05a 100644 --- a/setup.py +++ b/setup.py @@ -5,7 +5,7 @@ setuptools.setup( name="lennoxs30api", - version="0.1.8", + version="0.1.9", description="API Wrapper for Lennox S30 Cloud and LAN API", long_description=long_description, long_description_content_type="text/markdown", diff --git a/simulator/main.py b/simulator/main.py index 23e5f2f..21c90fb 100644 --- a/simulator/main.py +++ b/simulator/main.py @@ -21,6 +21,7 @@ def __init__(self, configfile: str): self.appList = {} self.zoneSimRunning = False self.outdoorTempSimRunning = False + self.siblingSimRunning = False with open(configfile) as f: self.config_data = json.load(f) @@ -105,6 +106,67 @@ async def zoneSimulator(self): humidity = humidity + 1 await asyncio.sleep(5.0) + async def siblingSimulator(self): + if self.siblingSimRunning == True: + return + self.siblingSimRunning = True + message = { + "MessageId": 0, + "SenderID": "LCC", + "TargetID": "homeassistant", + "MessageType": "PropertyChange", + "Data": { + "siblings": [ + { + "publisher": {"publisherName": "lcc"}, + "id": 0, + "selfIdentifier": "KL21J00001", + "sibling": { + "identifier": "KL21J00002", + "systemName": '"Bedrooms"', + "nodePresent": True, + "portNumber": 443, + "groupCountTracker": True, + "ipAddress": "10.0.0.2", + }, + } + ] + }, + } + for appName, appObject in self.appList.items(): + appObject.queue.append(message) + await asyncio.sleep(15.0) + + temperature = 100 + while True: + if temperature == 100: + status = LENNOX_STATUS_NOT_AVAILABLE + else: + status = LENNOX_STATUS_GOOD + message = { + "MessageId": "637594500464320381|95a6cacebd94459dbe7538161628bdb6", + "SenderId": "KL21J00002", + "TargetID": "mapp079372367644467046827098_myemail@email.com", + "MessageType": "PropertyChange", + "Data": { + "system": { + "status": { + "outdoorTemperatureStatus": status, + "outdoorTemperature": temperature, + "outdoorTemperatureC": 13.5, + }, + "publisher": {"publisherName": "lcc"}, + } + }, + } + for appName, appObject in self.appList.items(): + appObject.queue.append(message) + if temperature == 200: + temperature = 100 + else: + temperature = temperature + 10 + await asyncio.sleep(5.0) + def loadfile(self, name) -> json: script_dir = os.path.dirname(__file__) file_path = os.path.join(script_dir, "../" + name) @@ -142,6 +204,7 @@ async def request_data(self, request: Request): app.queue.append(data) asyncio.create_task(self.outdoorTempSimulator()) asyncio.create_task(self.zoneSimulator()) + asyncio.create_task(self.siblingSimulator()) return web.Response(text="Simulator Success") return web.Response(status=404, text="Simulator Failuer") diff --git a/tests/messages/sibling.json b/tests/messages/sibling.json new file mode 100644 index 0000000..e228d2e --- /dev/null +++ b/tests/messages/sibling.json @@ -0,0 +1,25 @@ +{ + "MessageId": 0, + "SenderID": "0000000-0000-0000-0000-000000000002", + "TargetID": "homeassistant", + "MessageType": "PropertyChange", + "Data": { + "siblings": [ + { + "publisher": { + "publisherName": "lcc" + }, + "id": 0, + "selfIdentifier": "KL21J00001", + "sibling": { + "identifier": "KL21J00002", + "systemName": "\"Bedrooms\"", + "nodePresent": true, + "portNumber": 443, + "groupCountTracker": true, + "ipAddress": "10.0.0.2" + } + } + ] + } +} diff --git a/tests/messages/sibling_multiple.json b/tests/messages/sibling_multiple.json new file mode 100644 index 0000000..0e74830 --- /dev/null +++ b/tests/messages/sibling_multiple.json @@ -0,0 +1,42 @@ +{ + "_comment" : "This is not a real messages that was captured, it's purpose is to test error handling", + "MessageId": 0, + "SenderID": "0000000-0000-0000-0000-000000000002", + "TargetID": "homeassistant", + "MessageType": "PropertyChange", + "Data": { + "siblings": [ + { + "publisher": { + "publisherName": "lcc" + }, + "id": 0, + "selfIdentifier": "KL21J00001", + "sibling": { + "identifier": "KL21J00002", + "systemName": "\"Bedrooms\"", + "nodePresent": true, + "portNumber": 443, + "groupCountTracker": true, + "ipAddress": "10.0.0.2" + } + }, + { + "publisher": { + "publisherName": "lcc" + }, + "id": 0, + "selfIdentifier": "KL21J00003", + "sibling": { + "identifier": "KL21J00004", + "systemName": "\"Living Room\"", + "nodePresent": true, + "portNumber": 443, + "groupCountTracker": true, + "ipAddress": "10.0.0.3" + } + } + + ] + } +} diff --git a/tests/messages/sibling_zero.json b/tests/messages/sibling_zero.json new file mode 100644 index 0000000..70f0017 --- /dev/null +++ b/tests/messages/sibling_zero.json @@ -0,0 +1,11 @@ +{ + "_comment" : "This is not a real messages that was captured, it's purpose is to test error handling", + "MessageId": 0, + "SenderID": "0000000-0000-0000-0000-000000000002", + "TargetID": "homeassistant", + "MessageType": "PropertyChange", + "Data": { + "siblings": [ + ] + } +} diff --git a/tests/test_api_process_message.py b/tests/test_api_process_message.py new file mode 100644 index 0000000..a9aaefe --- /dev/null +++ b/tests/test_api_process_message.py @@ -0,0 +1,53 @@ +import logging +from lennoxs30api.s30api_async import ( + lennox_system, + s30api_async, +) + +from tests.conftest import loadfile + + +def test_api_process_sibling_message(api: s30api_async, caplog): + lsystem: lennox_system = api.getSystems()[1] + assert lsystem.sysId == "0000000-0000-0000-0000-000000000002" + + message = loadfile("sibling.json") + api.processMessage(message) + + assert lsystem.sibling_self_identifier == "KL21J00001" + assert lsystem.sibling_identifier == "KL21J00002" + assert api.metrics.sibling_message_drop == 0 + message = loadfile("mut_sys1_zone1_status.json") + message["SenderId"] = "KL21J00002" + caplog.clear() + api.metrics.reset() + with caplog.at_level(logging.DEBUG): + api.processMessage(message) + assert len(caplog.records) == 1 + assert "KL21J00002" in caplog.messages[0] + assert caplog.records[0].levelname == "WARNING" + assert api.metrics.sibling_message_drop == 1 + assert api.metrics.sender_message_drop == 0 + + api.processMessage(message) + assert len(caplog.records) == 2 + assert "KL21J00002" in caplog.messages[1] + assert caplog.records[1].levelname == "DEBUG" + assert api.metrics.sibling_message_drop == 2 + assert api.metrics.sender_message_drop == 0 + + +def test_api_process_unknown_sender(api: s30api_async, caplog): + lsystem: lennox_system = api.getSystems()[1] + assert lsystem.sysId == "0000000-0000-0000-0000-000000000002" + message = loadfile("mut_sys1_zone1_status.json") + message["SenderId"] = "KL21J00002" + caplog.clear() + api.metrics.reset() + with caplog.at_level(logging.DEBUG): + api.processMessage(message) + assert len(caplog.records) == 1 + assert "KL21J00002" in caplog.messages[0] + assert caplog.records[0].levelname == "ERROR" + assert api.metrics.sibling_message_drop == 0 + assert api.metrics.sender_message_drop == 1 diff --git a/tests/test_message_logger.py b/tests/test_message_logger.py index 616aa5e..674171a 100644 --- a/tests/test_message_logger.py +++ b/tests/test_message_logger.py @@ -115,3 +115,17 @@ def test_logging_redacted_performance(caplog): ) print(t1) pass + + +def test_logger_instances_separate(caplog): + # Message Loggers are unique per file. So when specifying different files we should get different loggers + mlog1 = MessageLogger(enabled=True, message_logging_file="s30_log_file_1.tmp") + mlog2 = MessageLogger(enabled=True, message_logging_file="s30_log_file_2.tmp") + assert mlog1.logger != mlog2.logger + + # Message Loggers are unique per file. So when specifying different files we should get the same logger + mlog1 = MessageLogger(enabled=True, message_logging_file="s30_log file_1.tmp") + mlog2 = MessageLogger(enabled=True, message_logging_file="s30_log file_1.tmp") + assert mlog1.logger == mlog2.logger + # There should only be one handler for the loggers. + assert len(mlog1.logger.handlers) == 1 diff --git a/tests/test_siblings.py b/tests/test_siblings.py new file mode 100644 index 0000000..6aae019 --- /dev/null +++ b/tests/test_siblings.py @@ -0,0 +1,81 @@ +import logging +from lennoxs30api.s30api_async import ( + lennox_system, + s30api_async, +) + +from tests.conftest import loadfile + + +def test_process_sibling_message(api: s30api_async): + lsystem: lennox_system = api.getSystems()[1] + assert lsystem.sysId == "0000000-0000-0000-0000-000000000002" + + assert lsystem.sibling_self_identifier == None + assert lsystem.sibling_identifier == None + assert lsystem.sibling_systemName == None + assert lsystem.sibling_nodePresent == None + assert lsystem.sibling_portNumber == None + assert lsystem.sibling_ipAddress == None + + message = loadfile("sibling.json") + api.processMessage(message) + + assert lsystem.sibling_self_identifier == "KL21J00001" + assert lsystem.sibling_identifier == "KL21J00002" + assert lsystem.sibling_systemName == '"Bedrooms"' + assert lsystem.sibling_nodePresent == True + assert lsystem.sibling_portNumber == 443 + assert lsystem.sibling_ipAddress == "10.0.0.2" + + +def test_process_multiple_sibling_message(api: s30api_async, caplog): + lsystem: lennox_system = api.getSystems()[1] + assert lsystem.sysId == "0000000-0000-0000-0000-000000000002" + + assert lsystem.sibling_self_identifier == None + assert lsystem.sibling_identifier == None + assert lsystem.sibling_systemName == None + assert lsystem.sibling_nodePresent == None + assert lsystem.sibling_portNumber == None + assert lsystem.sibling_ipAddress == None + + # Testing the error reporting if we encouter multiple siblings + message = loadfile("sibling_multiple.json") + caplog.clear() + with caplog.at_level(logging.ERROR): + api.processMessage(message) + # The first record should process + assert lsystem.sibling_self_identifier == "KL21J00001" + assert lsystem.sibling_identifier == "KL21J00002" + assert lsystem.sibling_systemName == '"Bedrooms"' + assert lsystem.sibling_nodePresent == True + assert lsystem.sibling_portNumber == 443 + assert lsystem.sibling_ipAddress == "10.0.0.2" + assert len(caplog.records) == 1 + assert "KL21J00003" in caplog.messages[0] + assert "KL21J00004" in caplog.messages[0] + + +def test_process_zero_sibling_message(api: s30api_async, caplog): + lsystem: lennox_system = api.getSystems()[1] + assert lsystem.sysId == "0000000-0000-0000-0000-000000000002" + + assert lsystem.sibling_self_identifier == None + assert lsystem.sibling_identifier == None + assert lsystem.sibling_systemName == None + assert lsystem.sibling_nodePresent == None + assert lsystem.sibling_portNumber == None + assert lsystem.sibling_ipAddress == None + + message = loadfile("sibling_zero.json") + caplog.clear() + with caplog.at_level(logging.ERROR): + api.processMessage(message) + assert lsystem.sibling_self_identifier == None + assert lsystem.sibling_identifier == None + assert lsystem.sibling_systemName == None + assert lsystem.sibling_nodePresent == None + assert lsystem.sibling_portNumber == None + assert lsystem.sibling_ipAddress == None + assert len(caplog.records) == 0