fix: add extra logging

Author: CodeFoodPixels

custom_components/robovac/tuyalocalapi.py

@@ -527,7 +527,7 @@ async def async_send(self):
         await self.device._async_send(self)
 
     @classmethod
-    def from_bytes(cls, data, cipher=None):
+    def from_bytes(cls, device, data, cipher=None):
         try:
             prefix, sequence, command, payload_size = struct.unpack_from(
                 MESSAGE_PREFIX_FORMAT, data
@@ -584,15 +584,15 @@ def from_bytes(cls, data, cipher=None):
             try:
                 payload_text = payload_data.decode("utf8")
             except UnicodeDecodeError as e:
-                _LOGGER.debug(payload_data.hex())
-                _LOGGER.error(e)
+                device._LOGGER.debug(payload_data.hex())
+                device._LOGGER.error(e)
                 raise MessageDecodeFailed() from e
             try:
                 payload = json.loads(payload_text)
             except json.decoder.JSONDecodeError as e:
                 # data may be encrypted
-                _LOGGER.debug(payload_data.hex())
-                _LOGGER.error(e)
+                device._LOGGER.debug(payload_data.hex())
+                device._LOGGER.error(e)
                 raise MessageDecodeFailed() from e
 
         return cls(command, payload, sequence)
@@ -614,6 +614,7 @@ def __init__(
         version=(3, 3),
     ):
         """Initialize the device."""
+        self._LOGGER = _LOGGER.getChild(device_id)
         self.device_id = device_id
         self.host = host
         self.port = port
@@ -668,7 +669,7 @@ async def process_queue(self):
         self.clean_queue()
 
         if len(self._queue) > 0:
-            _LOGGER.debug(
+            self._LOGGER.debug(
                 "Processing queue. Current length: {}".format(len(self._queue))
             )
             try:
@@ -679,14 +680,16 @@ async def process_queue(self):
                 self._backoff = False
             except Exception as e:
                 self._failures += 1
-                _LOGGER.debug("{} failures. Most recent: {}".format(self._failures, e))
+                self._LOGGER.debug(
+                    "{} failures. Most recent: {}".format(self._failures, e)
+                )
                 if self._failures > 3:
                     self._backoff = True
                     self._queue_interval = min(
                         INITIAL_BACKOFF * (BACKOFF_MULTIPLIER ** (self._failures - 4)),
                         600,
                     )
-                    _LOGGER.warn(
+                    self._LOGGER.warn(
                         "{} failures, backing off for {} seconds".format(
                             self._failures, self._queue_interval
                         )
@@ -709,7 +712,7 @@ async def async_connect(self):
 
         sock = socket.socket(family=socket.AF_INET, type=socket.SOCK_STREAM)
         sock.settimeout(self.timeout)
-        _LOGGER.debug("Connecting to {}".format(self))
+        self._LOGGER.debug("Connecting to {}".format(self))
         try:
             sock.connect((self.host, self.port))
         except (socket.timeout, TimeoutError) as e:
@@ -734,7 +737,7 @@ async def async_disconnect(self):
         if self._connected is False:
             return
 
-        _LOGGER.debug("Disconnected from {}".format(self))
+        self._LOGGER.debug("Disconnected from {}".format(self))
         self._connected = False
         self.last_pong = 0
 
@@ -769,7 +772,7 @@ async def async_ping(self, ping_interval):
             return
 
         if self._backoff is True:
-            _LOGGER.debug("Currently in backoff, not adding ping to queue")
+            self._LOGGER.debug("Currently in backoff, not adding ping to queue")
         else:
             self.last_ping = time.time()
             encrypt = False if self.version < (3, 3) else True
@@ -801,7 +804,7 @@ async def async_update_state(self, state_message, _=None):
             and state_message.payload["dps"]
         ):
             self._dps.update(state_message.payload["dps"])
-            _LOGGER.debug("Received updated state {}: {}".format(self, self._dps))
+            self._LOGGER.debug("Received updated state {}: {}".format(self, self._dps))
 
     @property
     def state(self):
@@ -821,21 +824,23 @@ async def _async_handle_message(self):
             )
             await self._response_task
             response_data = self._response_task.result()
-            message = Message.from_bytes(response_data, self.cipher)
+            message = Message.from_bytes(self, response_data, self.cipher)
         except Exception as e:
             if isinstance(e, InvalidMessage):
-                _LOGGER.debug("Invalid message from {}: {}".format(self, e))
+                self._LOGGER.debug("Invalid message from {}: {}".format(self, e))
             elif isinstance(e, MessageDecodeFailed):
-                _LOGGER.debug("Failed to decrypt message from {}".format(self))
+                self._LOGGER.debug("Failed to decrypt message from {}".format(self))
             elif isinstance(e, asyncio.IncompleteReadError):
                 if self._connected:
-                    _LOGGER.debug("Incomplete read")
+                    self._LOGGER.debug("Incomplete read")
             elif isinstance(e, ConnectionResetError):
-                _LOGGER.debug("Connection reset: {}".format(e))
+                self._LOGGER.debug(
+                    "Connection reset: {}\n{}".format(e, e.__traceback__)
+                )
                 await self.async_disconnect()
 
         else:
-            _LOGGER.debug("Received message from {}: {}".format(self, message))
+            self._LOGGER.debug("Received message from {}: {}".format(self, message))
             if message.sequence in self._listeners:
                 sem = self._listeners[message.sequence]
                 if isinstance(sem, asyncio.Semaphore):
@@ -850,7 +855,7 @@ async def _async_handle_message(self):
         asyncio.create_task(self._async_handle_message())
 
     async def _async_send(self, message, retries=2):
-        _LOGGER.debug("Sending to {}: {}".format(self, message))
+        self._LOGGER.debug("Sending to {}: {}".format(self, message))
         try:
             await self.async_connect()
             self.writer.write(message.bytes())
@@ -871,19 +876,19 @@ async def _async_send(self, message, retries=2):
                     raise TuyaException("Failed to send data to {}".format(self))
 
             if isinstance(e, socket.error):
-                _LOGGER.debug(
+                self._LOGGER.debug(
                     "Retrying send due to error. Connection to {} failed: {}".format(
                         self, e
                     )
                 )
             elif isinstance(e, asyncio.IncompleteReadError):
-                _LOGGER.debug(
+                self._LOGGER.debug(
                     "Retrying send due to error. Incomplete read from: {} : {}. Partial data recieved: {}".format(
                         self, e, e.partial
                     )
                 )
             else:
-                _LOGGER.debug(
+                self._LOGGER.debug(
                     "Retrying send due to error. Failed to send data to {}".format(self)
                 )
             await asyncio.sleep(0.25)