feat: add device name to logs (#100)

Author: Lash-L

roborock/api.py

@@ -64,7 +64,7 @@
     RoborockMessageProtocol,
 )
 from .roborock_typing import DeviceProp, DockSummary, RoborockCommand
-from .util import RepeatableTask, get_running_loop_or_create_one, unpack_list
+from .util import RepeatableTask, RoborockLoggerAdapter, get_running_loop_or_create_one, unpack_list
 
 _LOGGER = logging.getLogger(__name__)
 KEEPALIVE = 60
@@ -166,6 +166,7 @@ def __init__(self, endpoint: str, device_info: DeviceData) -> None:
         self._last_disconnection = self.time_func()
         self.keep_alive = KEEPALIVE
         self._diagnostic_data: dict[str, dict[str, Any]] = {}
+        self._logger = RoborockLoggerAdapter(device_info.device.name, _LOGGER)
         cache = device_cache.get(device_info.device.duid)
         if not cache:
             cache = {
@@ -240,13 +241,13 @@ def on_message_received(self, messages: list[RoborockMessage]) -> None:
                         else:
                             try:
                                 data_protocol = RoborockDataProtocol(int(data_point_number))
-                                _LOGGER.debug(f"Got device update for {data_protocol.name}: {data_point}")
+                                self._logger.debug(f"Got device update for {data_protocol.name}: {data_point}")
                                 if data_protocol in ROBOROCK_DATA_STATUS_PROTOCOL:
                                     _cls: Type[Status] = ModelStatus.get(
                                         self.device_info.model, S7MaxVStatus
                                     )  # Default to S7 MAXV if we don't have the data
                                     if self.cache[CacheableAttribute.status].value is None:
-                                        _LOGGER.debug(
+                                        self._logger.debug(
                                             f"Got status update({data_protocol.name}) before get_status was called."
                                         )
                                         self.cache[CacheableAttribute.status]._value = {}
@@ -257,7 +258,7 @@ def on_message_received(self, messages: list[RoborockMessage]) -> None:
                                         listener(CacheableAttribute.status, status)
                                 elif data_protocol in ROBOROCK_DATA_CONSUMABLE_PROTOCOL:
                                     if self.cache[CacheableAttribute.consumable].value is None:
-                                        _LOGGER.debug(
+                                        self._logger.debug(
                                             f"Got consumable update({data_protocol.name}) before get_status was called."
                                         )
                                         self.cache[CacheableAttribute.consumable]._value = {}
@@ -270,7 +271,7 @@ def on_message_received(self, messages: list[RoborockMessage]) -> None:
                             except ValueError:
                                 pass
                             dps = {data_point_number: data_point}
-                            _LOGGER.debug(f"Got unknown data point {dps}")
+                            self._logger.debug(f"Got unknown data point {dps}")
                 elif data.payload and protocol == RoborockMessageProtocol.MAP_RESPONSE:
                     payload = data.payload[0:24]
                     [endpoint, _, request_id, _] = struct.unpack("<8s8sH6s", payload)
@@ -287,13 +288,13 @@ def on_message_received(self, messages: list[RoborockMessage]) -> None:
                     if queue:
                         queue.resolve((data.payload, None))
         except Exception as ex:
-            _LOGGER.exception(ex)
+            self._logger.exception(ex)
 
     def on_connection_lost(self, exc: Optional[Exception]) -> None:
         self._last_disconnection = self.time_func()
-        _LOGGER.info("Roborock client disconnected")
+        self._logger.info("Roborock client disconnected")
         if exc is not None:
-            _LOGGER.warning(exc)
+            self._logger.warning(exc)
 
     def should_keepalive(self) -> bool:
         now = self.time_func()

roborock/cloud_api.py

@@ -17,6 +17,7 @@
 from .roborock_future import RoborockFuture
 from .roborock_message import RoborockMessage, RoborockMessageProtocol
 from .roborock_typing import RoborockCommand
+from .util import RoborockLoggerAdapter
 
 _LOGGER = logging.getLogger(__name__)
 CONNECT_REQUEST_ID = 0
@@ -34,6 +35,7 @@ def __init__(self, user_data: UserData, device_info: DeviceData) -> None:
         endpoint = base64.b64encode(Utils.md5(rriot.k.encode())[8:14]).decode()
         RoborockClient.__init__(self, endpoint, device_info)
         mqtt.Client.__init__(self, protocol=mqtt.MQTTv5)
+        self._logger = RoborockLoggerAdapter(device_info.device.name, _LOGGER)
         self._mqtt_user = rriot.u
         self._hashed_user = md5hex(self._mqtt_user + ":" + rriot.k)[2:10]
         url = urlparse(rriot.r.m)
@@ -57,20 +59,20 @@ def on_connect(self, *args, **kwargs):
         connection_queue = self._waiting_queue.get(CONNECT_REQUEST_ID)
         if rc != mqtt.MQTT_ERR_SUCCESS:
             message = f"Failed to connect ({mqtt.error_string(rc)})"
-            _LOGGER.error(message)
+            self._logger.error(message)
             if connection_queue:
                 connection_queue.resolve((None, VacuumError(message)))
             return
-        _LOGGER.info(f"Connected to mqtt {self._mqtt_host}:{self._mqtt_port}")
+        self._logger.info(f"Connected to mqtt {self._mqtt_host}:{self._mqtt_port}")
         topic = f"rr/m/o/{self._mqtt_user}/{self._hashed_user}/{self.device_info.device.duid}"
         (result, mid) = self.subscribe(topic)
         if result != 0:
             message = f"Failed to subscribe ({mqtt.error_string(rc)})"
-            _LOGGER.error(message)
+            self._logger.error(message)
             if connection_queue:
                 connection_queue.resolve((None, VacuumError(message)))
             return
-        _LOGGER.info(f"Subscribed to topic {topic}")
+        self._logger.info(f"Subscribed to topic {topic}")
         if connection_queue:
             connection_queue.resolve((True, None))
 
@@ -80,7 +82,7 @@ def on_message(self, *args, **kwargs):
             messages, _ = MessageParser.parse(msg.payload, local_key=self.device_info.device.local_key)
             super().on_message_received(messages)
         except Exception as ex:
-            _LOGGER.exception(ex)
+            self._logger.exception(ex)
 
     def on_disconnect(self, *args, **kwargs):
         _, __, rc, ___ = args
@@ -93,26 +95,26 @@ def on_disconnect(self, *args, **kwargs):
             if connection_queue:
                 connection_queue.resolve((True, None))
         except Exception as ex:
-            _LOGGER.exception(ex)
+            self._logger.exception(ex)
 
     def update_client_id(self):
         self._client_id = mqtt.base62(uuid.uuid4().int, padding=22)
 
     def sync_stop_loop(self) -> None:
         if self._thread:
-            _LOGGER.info("Stopping mqtt loop")
+            self._logger.info("Stopping mqtt loop")
             super().loop_stop()
 
     def sync_start_loop(self) -> None:
         if not self._thread or not self._thread.is_alive():
             self.sync_stop_loop()
-            _LOGGER.info("Starting mqtt loop")
+            self._logger.info("Starting mqtt loop")
             super().loop_start()
 
     def sync_disconnect(self) -> bool:
         rc = mqtt.MQTT_ERR_AGAIN
         if self.is_connected():
-            _LOGGER.info("Disconnecting from mqtt")
+            self._logger.info("Disconnecting from mqtt")
             rc = super().disconnect()
             if rc not in [mqtt.MQTT_ERR_SUCCESS, mqtt.MQTT_ERR_NO_CONN]:
                 raise RoborockException(f"Failed to disconnect ({mqtt.error_string(rc)})")
@@ -123,7 +125,7 @@ def sync_connect(self) -> bool:
         if should_connect:
             if self._mqtt_port is None or self._mqtt_host is None:
                 raise RoborockException("Mqtt information was not entered. Cannot connect.")
-            _LOGGER.info("Connecting to mqtt")
+            self._logger.info("Connecting to mqtt")
             super().connect(host=self._mqtt_host, port=self._mqtt_port, keepalive=KEEPALIVE)
         self.sync_start_loop()
         return should_connect
@@ -162,7 +164,7 @@ async def send_message(self, roborock_message: RoborockMessage):
 
         local_key = self.device_info.device.local_key
         msg = MessageParser.build(roborock_message, local_key, False)
-        _LOGGER.debug(f"id={request_id} Requesting method {method} with {params}")
+        self._logger.debug(f"id={request_id} Requesting method {method} with {params}")
         self._send_msg_raw(msg)
         (response, err) = await self._async_response(request_id, response_protocol)
         self._diagnostic_data[method if method is not None else "unknown"] = {
@@ -173,9 +175,9 @@ async def send_message(self, roborock_message: RoborockMessage):
         if err:
             raise CommandVacuumError(method, err) from err
         if response_protocol == RoborockMessageProtocol.MAP_RESPONSE:
-            _LOGGER.debug(f"id={request_id} Response from {method}: {len(response)} bytes")
+            self._logger.debug(f"id={request_id} Response from {method}: {len(response)} bytes")
         else:
-            _LOGGER.debug(f"id={request_id} Response from {method}: {response}")
+            self._logger.debug(f"id={request_id} Response from {method}: {response}")
         return response
 
     async def _send_command(

roborock/local_api.py

@@ -13,6 +13,7 @@
 from .protocol import MessageParser
 from .roborock_message import MessageRetry, RoborockMessage, RoborockMessageProtocol
 from .roborock_typing import RoborockCommand
+from .util import RoborockLoggerAdapter
 
 _LOGGER = logging.getLogger(__name__)
 
@@ -29,6 +30,7 @@ def __init__(self, device_data: DeviceData):
         self.transport: Transport | None = None
         self._mutex = Lock()
         self.keep_alive_task: TimerHandle | None = None
+        self._logger = RoborockLoggerAdapter(device_data.device.name, _LOGGER)
 
     def data_received(self, message):
         if self.remaining:
@@ -58,11 +60,11 @@ async def async_connect(self) -> None:
                 if not self.is_connected():
                     self.sync_disconnect()
                     async with async_timeout.timeout(QUEUE_TIMEOUT):
-                        _LOGGER.info(f"Connecting to {self.host}")
+                        self._logger.info(f"Connecting to {self.host}")
                         self.transport, _ = await self.event_loop.create_connection(  # type: ignore
                             lambda: self, self.host, 58867
                         )
-                        _LOGGER.info(f"Connected to {self.host}")
+                        self._logger.info(f"Connected to {self.host}")
                         should_ping = True
             except BaseException as e:
                 raise RoborockConnectionException(f"Failed connecting to {self.host}") from e
@@ -72,7 +74,7 @@ async def async_connect(self) -> None:
 
     def sync_disconnect(self) -> None:
         if self.transport and self.event_loop.is_running():
-            _LOGGER.debug(f"Disconnecting from {self.host}")
+            self._logger.debug(f"Disconnecting from {self.host}")
             self.transport.close()
         if self.keep_alive_task:
             self.keep_alive_task.cancel()
@@ -104,7 +106,7 @@ async def hello(self):
                 )
             )
         except Exception as e:
-            _LOGGER.error(e)
+            self._logger.error(e)
 
     async def ping(self):
         request_id = 2
@@ -149,7 +151,7 @@ async def send_message(self, roborock_message: RoborockMessage):
         local_key = self.device_info.device.local_key
         msg = MessageParser.build(roborock_message, local_key=local_key)
         if method:
-            _LOGGER.debug(f"id={request_id} Requesting method {method} with {params}")
+            self._logger.debug(f"id={request_id} Requesting method {method} with {params}")
         # Send the command to the Roborock device
         self._send_msg_raw(msg)
         (response, err) = await self._async_response(request_id, response_protocol)
@@ -161,7 +163,7 @@ async def send_message(self, roborock_message: RoborockMessage):
         if err:
             raise CommandVacuumError(method, err) from err
         if roborock_message.protocol == RoborockMessageProtocol.GENERAL_REQUEST:
-            _LOGGER.debug(f"id={request_id} Response from method {roborock_message.get_method()}: {response}")
+            self._logger.debug(f"id={request_id} Response from method {roborock_message.get_method()}: {response}")
         if response == "retry":
             retry_id = roborock_message.get_retry_id()
             return self.send_command(

roborock/util.py

@@ -3,8 +3,10 @@
 import asyncio
 import datetime
 import functools
+import logging
 from asyncio import AbstractEventLoop, TimerHandle
-from typing import Callable, Coroutine, Optional, Tuple, TypeVar
+from collections.abc import MutableMapping
+from typing import Any, Callable, Coroutine, Optional, Tuple, TypeVar
 
 from roborock import RoborockException
 
@@ -97,3 +99,13 @@ def cancel(self):
     async def reset(self):
         self.cancel()
         return await self._run_task()
+
+
+class RoborockLoggerAdapter(logging.LoggerAdapter):
+    def __init__(self, prefix: str, logger: logging.Logger) -> None:
+
+        super().__init__(logger, {})
+        self.prefix = prefix
+
+    def process(self, msg: str, kwargs: MutableMapping[str, Any]) -> tuple[str, MutableMapping[str, Any]]:
+        return "[%s] %s" % (self.prefix, msg), kwargs