added error handling and improved logging

nspanel-lovelace-ui/rootfs/usr/bin/mqtt-manager/ha_cards.py

@@ -475,7 +475,7 @@ class AlarmCard(HACard):
         main_entity = self.entities[0]
         main_entity.render()
 
-        print(main_entity.state)
+        logging.debug("Alarm card state for '%s': %s", main_entity.entity_id, main_entity.state)
 
         icon = get_icon_char("shield-off")
         color = rgb_dec565([255,255,255])

nspanel-lovelace-ui/rootfs/usr/bin/mqtt-manager/ha_control.py

@@ -8,6 +8,8 @@ def wait_for_ha_cache():
     while time.time() < mustend:
         if len(libs.home_assistant.home_assistant_entity_state_cache) == 0:
             time.sleep(0.1)
+    if len(libs.home_assistant.home_assistant_entity_state_cache) == 0:
+        logging.warning("Home Assistant entity cache is still empty after waiting 5 seconds")
     time.sleep(1)
 
 def calculate_dim_values(sleepTracking, sleepTrackingZones, sleepBrightness, screenBrightness, sleepOverride, return_involved_entities=False):
@@ -28,8 +30,8 @@ def calculate_dim_values(sleepTracking, sleepTrackingZones, sleepBrightness, scr
             involved_entities.append(sleepBrightness)
             try:
                 dimmode = int(float(libs.home_assistant.get_entity_data(sleepBrightness).get('state', 10)))
-            except ValueError:
+            except (TypeError, ValueError):
-                print("sleepBrightness entity invalid")
+                logging.exception("sleepBrightness entity '%s' has an invalid state value", sleepBrightness)
 
     if screenBrightness:
         if isinstance(screenBrightness, int):
@@ -44,8 +46,8 @@ def calculate_dim_values(sleepTracking, sleepTrackingZones, sleepBrightness, scr
             involved_entities.append(screenBrightness)
             try:
                 dimValueNormal = int(float(libs.home_assistant.get_entity_data(screenBrightness).get('state', 100)))
-            except ValueError:
+            except (TypeError, ValueError):
-                print("screenBrightness entity invalid")
+                logging.exception("screenBrightness entity '%s' has an invalid state value", screenBrightness)
     # force sleep brightness to zero in case sleepTracking is active
     if sleepTracking:
         if libs.home_assistant.is_existent(sleepTracking):
@@ -237,12 +239,19 @@ def handle_buttons(entity_id, btype, value, entity_config=None):
 
 def call_ha_service(entity_id, service, service_data = {}):
     etype = entity_id.split(".")[0]
-    libs.home_assistant.call_service(
+    ok = libs.home_assistant.call_service(
         entity_name=entity_id,
         domain=etype,
         service=service,
         service_data=service_data
     )
+    if not ok:
+        logging.error(
+            "Home Assistant service call failed: entity='%s', service='%s', data=%s",
+            entity_id,
+            service,
+            service_data,
+        )
 
 def button_press(entity_id, value):
     etype = entity_id.split(".")[0]

nspanel-lovelace-ui/rootfs/usr/bin/mqtt-manager/libs/home_assistant.py

@@ -16,6 +16,7 @@ ws_connected = False
 home_assistant_entity_state_cache = {}
 template_cache = {}
 response_buffer = {}
+nspanel_event_handler = None
 
 
 ON_CONNECT_HANDLER = None
@@ -46,10 +47,16 @@ def register_on_disconnect_handler(handler):
 
 def on_message(ws, message):
     global auth_ok, request_all_states_id, home_assistant_entity_state_cache, response_buffer, template_cache
-    json_msg = json.loads(message)
+    try:
-    if json_msg["type"] == "auth_required":
+        json_msg = json.loads(message)
+    except json.JSONDecodeError:
+        logging.exception("Failed to parse Home Assistant websocket message as JSON")
+        return
+
+    message_type = json_msg.get("type")
+    if message_type == "auth_required":
         authenticate_client()
-    elif json_msg["type"] == "auth_ok":
+    elif message_type == "auth_ok":
         auth_ok = True
         logging.info("Home Assistant auth OK. Requesting existing states.")
         subscribe_to_events()
@@ -57,30 +64,41 @@ def on_message(ws, message):
         if ON_CONNECT_HANDLER is not None:
             ON_CONNECT_HANDLER()
     # for templates
-    elif json_msg["type"] == "event" and json_msg["id"] in response_buffer:
+    elif message_type == "event" and json_msg.get("id") in response_buffer:
+        event = json_msg.get("event", {})
+        listeners = event.get("listeners", {})
         template_cache[response_buffer[json_msg["id"]]] = {
-            "result": json_msg["event"]["result"],
+            "result": event.get("result"),
-            "listener-entities": json_msg["event"]["listeners"]["entities"]
+            "listener-entities": listeners.get("entities", [])
         }
-    elif json_msg["type"] == "event" and json_msg["event"]["event_type"] == "state_changed":
+    elif message_type == "event" and json_msg.get("event", {}).get("event_type") == "state_changed":
-        entity_id = json_msg["event"]["data"]["entity_id"]
+        event_data = json_msg.get("event", {}).get("data", {})
-        home_assistant_entity_state_cache[entity_id] = json_msg["event"]["data"]["new_state"]
+        entity_id = event_data.get("entity_id")
+        if not entity_id:
+            logging.debug("Received state_changed event without entity_id")
+            return
+        home_assistant_entity_state_cache[entity_id] = event_data.get("new_state")
         send_entity_update(entity_id)
         # rerender template
         for template, template_cache_entry in template_cache.items():
             if entity_id in template_cache_entry.get("listener-entities", []):
                 cache_template(template)
-    elif json_msg["type"] == "event" and json_msg["event"]["event_type"] == "esphome.nspanel.data":
+    elif message_type == "event" and json_msg.get("event", {}).get("event_type") == "esphome.nspanel.data":
-        nspanel_data_callback(json_msg["event"]["data"]["device_id"], json_msg["event"]["data"]["CustomRecv"])
+        event_data = json_msg.get("event", {}).get("data", {})
-    elif json_msg["type"] == "result" and not json_msg["success"]:
+        device_id = event_data.get("device_id")
-        logging.error("Failed result: ")
+        custom_recv = event_data.get("CustomRecv")
-        logging.error(json_msg)
+        if nspanel_event_handler is None:
-    elif json_msg["type"] == "result" and json_msg["success"]:
+            logging.debug("No NsPanel event handler registered; dropping event for device '%s'", device_id)
-        if json_msg["id"] == request_all_states_id:
+            return
-            for entity in json_msg["result"]:
+        nspanel_event_handler(device_id, custom_recv)
+    elif message_type == "result" and not json_msg.get("success"):
+        logging.error("Home Assistant request failed: %s", json_msg)
+    elif message_type == "result" and json_msg.get("success"):
+        if json_msg.get("id") == request_all_states_id:
+            for entity in json_msg.get("result", []):
                 home_assistant_entity_state_cache[entity["entity_id"]] = entity
         else:
-            if json_msg["id"] in response_buffer and json_msg.get("result"):
+            if json_msg.get("id") in response_buffer and json_msg.get("result"):
                 response_buffer[json_msg["id"]] = json_msg["result"]
         return None  # Ignore success result messages
     else:
@@ -98,7 +116,11 @@ def _ws_connection_open(ws):
 def _ws_connection_close(ws, close_status_code, close_msg):
     global ws_connected
     ws_connected = False
-    logging.error("WebSocket connection closed!")
+    logging.error(
+        "WebSocket connection closed (status=%s, message=%s)",
+        close_status_code,
+        close_msg,
+    )
     if ON_DISCONNECT_HANDLER is not None:
         ON_DISCONNECT_HANDLER()
 
@@ -119,9 +141,12 @@ def _do_connection():
                                 on_open=_ws_connection_open, on_close=_ws_connection_close)
     while True:
         logging.info(F"Connecting to Home Assistant at {ws_url}")
-        ws.close()
+        try:
-        time.sleep(1)
+            ws.close()
-        ws.run_forever(sslopt={"cert_reqs": ssl.CERT_NONE})
+            time.sleep(1)
+            ws.run_forever(sslopt={"cert_reqs": ssl.CERT_NONE})
+        except Exception:
+            logging.exception("WebSocket connection loop failed")
         time.sleep(10)
 
 
@@ -145,8 +170,8 @@ def subscribe_to_events():
     send_message(json.dumps(msg))
 
 def subscribe_to_nspanel_events(nsp_callback):
-    global next_id, nspanel_data_callback
+    global next_id, nspanel_event_handler
-    nspanel_data_callback = nsp_callback
+    nspanel_event_handler = nsp_callback
     msg = {
         "id": next_id,
         "type": "subscribe_events",
@@ -169,8 +194,10 @@ def send_entity_update(entity_id):
     on_ha_update(entity_id)
 
 def nspanel_data_callback(device_id, msg):
-    global nspanel_data_callback
+    if nspanel_event_handler is None:
-    nspanel_data_callback(device_id, msg)
+        logging.debug("NsPanel callback invoked before handler was registered")
+        return
+    nspanel_event_handler(device_id, msg)
 
 def call_service(entity_name: str, domain: str, service: str, service_data: dict) -> bool:
     global next_id
@@ -187,8 +214,11 @@ def call_service(entity_name: str, domain: str, service: str, service_data: dict
         }
         send_message(json.dumps(msg))
         return True
-    except Exception as e:
+    except Exception:
-        logging.exception("Failed to call Home Assisatant service.")
+        logging.exception(
+            "Failed to call Home Assistant service: %s.%s for %s",
+            domain, service, entity_name
+        )
         return False
 
 def send_msg_to_panel(service: str, service_data: dict) -> bool:
@@ -203,8 +233,8 @@ def send_msg_to_panel(service: str, service_data: dict) -> bool:
         }
         send_message(json.dumps(msg))
         return True
-    except Exception as e:
+    except Exception:
-        logging.exception("Failed to call Home Assisatant service.")
+        logging.exception("Failed to call Home Assistant panel service: %s", service)
         return False
 
 def execute_script(entity_name: str, domain: str, service: str, service_data: dict) -> str:
@@ -241,13 +271,13 @@ def execute_script(entity_name: str, domain: str, service: str, service_data: di
             else:
                 return response_buffer[call_id]["response"]
         raise TimeoutError("Did not recive respose in time to HA script call")
-    except Exception as e:
+    except Exception:
-        logging.exception("Failed to call Home Assisatant script.")
+        logging.exception("Failed to call Home Assistant script: %s.%s", domain, service)
         return {}
 
 def cache_template(template):
     if not template:
-        raise Exception("Invalid template")
+        raise ValueError("Invalid template")
     global next_id, response_buffer
     try:
         call_id = next_id
@@ -259,7 +289,7 @@ def cache_template(template):
         }
         send_message(json.dumps(msg))
         return True
-    except Exception as e:
+    except Exception:
         logging.exception("Failed to render template.")
         return False
 
@@ -301,5 +331,10 @@ def is_existent(entity_id: str):
 
 def send_message(message):
     global ws, next_id
-    next_id += 1
+    try:
-    ws.send(message)
+        next_id += 1
+        ws.send(message)
+    except NameError:
+        logging.error("WebSocket client is not initialized; dropping outgoing message")
+    except Exception:
+        logging.exception("Failed sending websocket message to Home Assistant")

nspanel-lovelace-ui/rootfs/usr/bin/mqtt-manager/main.py

@@ -25,53 +25,68 @@ last_settings_file_mtime = 0
 mqtt_connect_time = 0
 has_sent_reload_command = False
 
-logging.basicConfig(level=logging.DEBUG)
+logging.basicConfig(
+    level=logging.DEBUG,
+    format="%(asctime)s %(levelname)s [%(threadName)s] %(name)s: %(message)s",
+)
 
 def on_ha_update(entity_id):
     global panel_in_queues
     # send HA updates to all panels
     for queue in panel_in_queues.values():
-        queue.put(("HA:", entity_id))
+        try:
+            queue.put(("HA:", entity_id))
+        except Exception:
+            logging.exception("Failed to enqueue HA update for entity '%s'", entity_id)
 
 def on_ha_panel_event(device_id, msg):
     global panel_in_queues
 
     if device_id in panel_in_queues.keys():
         queue = panel_in_queues[device_id]
-        queue.put(("MQTT:", msg))
+        try:
+            queue.put(("MQTT:", msg))
+        except Exception:
+            logging.exception("Failed to enqueue panel event for device '%s'", device_id)
 
 def process_output_to_panel():
     while True:
-        msg = panel_out_queue.get()
+        try:
-
+            msg = panel_out_queue.get()
-        #client.publish(msg[0], msg[1])
+            service = msg[0] + "_nspanelui_api_call"
-        #apis.ha_api.call_service(service="esphome/" + self._api_panel_name + "_nspanelui_api_call", command=2, data=msg)
+            service_data = {
-        service = msg[0] + "_nspanelui_api_call"
+                "data": msg[1],
-        service_data = {
+                "command": 2
-            "data": msg[1],
-            "command":2
             }
-        libs.home_assistant.send_msg_to_panel(
+            libs.home_assistant.send_msg_to_panel(
-            service = service,
+                service=service,
-            service_data = service_data
+                service_data=service_data
-        )
+            )
+        except Exception:
+            logging.exception("Failed to process outgoing panel message")
 
 
 def connect():
     global settings, panel_out_queue
+    ha_is_configured = settings["home_assistant_address"] != "" and settings["home_assistant_token"] != ""
     if "mqtt_server" in settings and not "use_ha_api" in settings:
         MqttManager(settings, panel_out_queue, panel_in_queues)
     else:
         logging.info("MQTT values not configured, will not connect.")
 
     # MQTT Connected, start APIs if configured
-    if settings["home_assistant_address"] != "" and settings["home_assistant_token"] != "":
+    if ha_is_configured:
         libs.home_assistant.init(settings, on_ha_update)
         libs.home_assistant.connect()
     else:
         logging.info("Home Assistant values not configured, will not connect.")
+        return
 
+    wait_seconds = 0
     while not libs.home_assistant.ws_connected:
+        wait_seconds += 1
+        if wait_seconds % 10 == 0:
+            logging.info("Waiting for Home Assistant websocket connection... (%ss)", wait_seconds)
         time.sleep(1)
     if settings.get("use_ha_api"):
         libs.home_assistant.subscribe_to_nspanel_events(on_ha_panel_event)
@@ -97,13 +112,20 @@ def setup_panels():
         panel_thread.start()
 
 def panel_thread_target(queue_in, name, settings_panel, queue_out):
-    panel = LovelaceUIPanel(name, settings_panel, queue_out)
+    try:
+        panel = LovelaceUIPanel(name, settings_panel, queue_out)
+    except Exception:
+        logging.exception("Failed to initialize panel thread for '%s'", name)
+        return
     while True:
-        msg = queue_in.get()
+        try:
-        if msg[0] == "MQTT:":
+            msg = queue_in.get()
-            panel.customrecv_event_callback(msg[1])
+            if msg[0] == "MQTT:":
-        elif msg[0] == "HA:":
+                panel.customrecv_event_callback(msg[1])
-            panel.ha_event_callback(msg[1])
+            elif msg[0] == "HA:":
+                panel.ha_event_callback(msg[1])
+        except Exception:
+            logging.exception("Panel thread '%s' failed while handling queue message", name)
 
 def get_config_file():
     CONFIG_FILE = os.getenv('CONFIG_FILE')
@@ -117,18 +139,27 @@ def get_config(file):
     try:
         with open(file, 'r', encoding="utf8") as file:
             settings = yaml.safe_load(file)
+    except FileNotFoundError:
+        logging.error("Config file not found: %s", file)
+        return False
+    except OSError:
+        logging.exception("Failed reading config file: %s", file)
+        return False
     except yaml.YAMLError as exc:
-        print ("Error while parsing YAML file:")
+        logging.error("Error while parsing YAML file: %s", file)
         if hasattr(exc, 'problem_mark'):
             if exc.context != None:
-                print ('  parser says\n' + str(exc.problem_mark) + '\n  ' +
+                logging.error(
-                    str(exc.problem) + ' ' + str(exc.context) +
+                    "Parser says\n%s\n%s %s\nPlease correct data and retry.",
-                    '\nPlease correct data and retry.')
+                    str(exc.problem_mark), str(exc.problem), str(exc.context)
+                )
             else:
-                print ('  parser says\n' + str(exc.problem_mark) + '\n  ' +
+                logging.error(
-                    str(exc.problem) + '\nPlease correct data and retry.')
+                    "Parser says\n%s\n%s\nPlease correct data and retry.",
+                    str(exc.problem_mark), str(exc.problem)
+                )
         else:
-            print ("Something went wrong while parsing yaml file")
+            logging.exception("Something went wrong while parsing yaml file")
         return False
 
     if not settings.get("mqtt_username"):
@@ -172,10 +203,14 @@ def config_watch():
     project_files.append(get_config_file())
     handler = ConfigChangeEventHandler(project_files)
     observer = Observer()
-    observer.schedule(handler, path=os.path.dirname(get_config_file()), recursive=True)
+    watch_path = os.path.dirname(get_config_file()) or "."
+    observer.schedule(handler, path=watch_path, recursive=True)
     observer.start()
     while True:
-        time.sleep(1)
+        try:
+            time.sleep(1)
+        except Exception:
+            logging.exception("Config watch loop failed")
 
 def signal_handler(signum, frame):
     logging.info(f"Received signal {signum}. Initiating restart...")

nspanel-lovelace-ui/rootfs/usr/bin/mqtt-manager/mqtt.py

@@ -19,7 +19,6 @@ class MqttManager:
         self.client.username_pw_set(
             settings["mqtt_username"], settings["mqtt_password"])
         # Wait for connection
-        connection_return_code = 0
         mqtt_server = settings["mqtt_server"]
         mqtt_port = int(settings["mqtt_port"])
         logging.info("Connecting to %s:%i as %s",
@@ -28,9 +27,12 @@ class MqttManager:
             try:
                 self.client.connect(mqtt_server, mqtt_port, 5)
                 break  # Connection call did not raise exception, connection is sucessfull
-            except:  # pylint: disable=bare-except
+            except Exception:  # pylint: disable=broad-exception-caught
                 logging.exception(
-                    "Failed to connect to MQTT %s:%i. Will try again in 10 seconds. Code: %s", mqtt_server, mqtt_port, connection_return_code)
+                    "Failed to connect to MQTT %s:%i. Will try again in 10 seconds.",
+                    mqtt_server,
+                    mqtt_port,
+                )
                 time.sleep(10.)
         self.client.loop_start()
         process_thread = threading.Thread(target=self.process_in_queue, args=(self.client, self.msg_in_queue))
@@ -38,31 +40,52 @@ class MqttManager:
         process_thread.start()
 
     def on_mqtt_connect(self, client, userdata, flags, rc):
+        if rc != 0:
+            logging.error("MQTT connection failed with return code: %s", rc)
+            return
         logging.info("Connected to MQTT Server")
         # subscribe to panelRecvTopic of each panel
         for settings_panel in self.settings["nspanels"].values():
-            client.subscribe(settings_panel["panelRecvTopic"])
+            topic = settings_panel["panelRecvTopic"]
+            result, _ = client.subscribe(topic)
+            if result == mqtt.MQTT_ERR_SUCCESS:
+                logging.debug("Subscribed to panel topic: %s", topic)
+            else:
+                logging.error("Failed to subscribe to panel topic '%s' (result=%s)", topic, result)
 
     def on_mqtt_message(self, client, userdata, msg):
         try:
-            if msg.payload.decode() == "":
+            payload_text = msg.payload.decode('utf-8')
+            if payload_text == "":
+                logging.debug("Ignoring empty MQTT payload on topic: %s", msg.topic)
                 return
             if msg.topic in self.msg_out_queue_list.keys():
-                data = json.loads(msg.payload.decode('utf-8'))
+                data = json.loads(payload_text)
                 if "CustomRecv" in data:
                     queue = self.msg_out_queue_list[msg.topic]
                     queue.put(("MQTT:", data["CustomRecv"]))
+                else:
+                    logging.debug("JSON payload on topic '%s' has no 'CustomRecv' key", msg.topic)
             else:
                 logging.debug("Received unhandled message on topic: %s", msg.topic)
+        except UnicodeDecodeError:
+            logging.exception("Failed to decode MQTT payload as UTF-8 on topic: %s", msg.topic)
+        except json.JSONDecodeError:
+            logging.exception("Failed to parse MQTT JSON payload on topic: %s", msg.topic)
         except Exception:  # pylint: disable=broad-exception-caught
-            logging.exception("Something went wrong during processing of message:")
+            logging.exception("Unexpected error while processing MQTT message on topic: %s", msg.topic)
             try:
                 logging.error(msg.payload.decode('utf-8'))
-            except:  # pylint: disable=bare-except
+            except Exception:  # pylint: disable=broad-exception-caught
                 logging.error(
                     "Something went wrong when processing the exception message, couldn't decode payload to utf-8.")
 
     def process_in_queue(self, client, msg_in_queue):
         while True:
-            msg = msg_in_queue.get()
+            try:
-            client.publish(msg[0], msg[1])
+                msg = msg_in_queue.get()
+                result = client.publish(msg[0], msg[1])
+                if result.rc != mqtt.MQTT_ERR_SUCCESS:
+                    logging.error("Failed publishing message to topic '%s' (rc=%s)", msg[0], result.rc)
+            except Exception:  # pylint: disable=broad-exception-caught
+                logging.exception("Failed processing outgoing MQTT queue message")

nspanel-lovelace-ui/rootfs/usr/bin/mqtt-manager/panel.py

@@ -105,7 +105,10 @@ class LovelaceUIPanel:
 
     def schedule_thread_target(self):
         while True:
-            self.schedule.exec_jobs()
+            try:
+                self.schedule.exec_jobs()
+            except Exception:
+                logging.exception("Scheduler execution failed for panel '%s'", self.name)
             time.sleep(1)
 
     def update_time(self):
@@ -203,6 +206,9 @@ class LovelaceUIPanel:
     def customrecv_event_callback(self, msg):
         logging.debug("Recv Message from NsPanel (%s): %s", self.name, msg)
         msg = msg.split(",")
+        if len(msg) < 2:
+            logging.error("Malformed panel message on '%s': %s", self.name, msg)
+            return
         # run action based on received command
         if msg[0] == "event":
             if msg[1] == "startup":
@@ -227,11 +233,15 @@ class LovelaceUIPanel:
             if msg[1] == "renderCurrentPage":
                 self.render_current_page(requested=True)
             if msg[1] == "buttonPress2":
+                if len(msg) < 4:
+                    logging.error("Malformed buttonPress2 payload on '%s': %s", self.name, msg)
+                    return
                 entity_id = msg[2]
                 if entity_id == "":
                     return
                 btype = msg[3]
                 value = msg[4] if len(msg) > 4 else None
+                entity_config = {}
                 if btype == "bExit":
                     if entity_id in ["screensaver", "screensaver2"] and self.settings.get("screensaver").get("doubleTapToUnlock") and value == "1":
                         return
@@ -286,14 +296,17 @@ class LovelaceUIPanel:
                         ha_control.handle_buttons(entity_id, btype, value)
 
             if msg[1] == "pageOpenDetail":
+                if len(msg) < 4:
+                    logging.error("Malformed pageOpenDetail payload on '%s': %s", self.name, msg)
+                    return
                 entity_id = msg[3]
+                effectList = None
                 # replace iid with real entity id
                 if entity_id.startswith("iid."):
                     iid = entity_id.split(".")[1]
                     for e in self.current_card.entities:
                         if e.iid == iid:
                             entity_id = e.entity_id
-                            effectList = None
                             if entity_id.startswith("light"):
                                 effectList = e.config.get("effectList")
                 if msg[2] == "popupInSel": #entity_id.split(".")[0] in ['input_select', 'media_player']: