websockets: sanitize verbose logging

When verbose logging is enabled sanitize credentials from JSON-RPC
requests and responses.

Signed-off-by:  Eric Callahan <arksine.code@gmail.com>

moonraker/components/mqtt.py

@@ -306,7 +306,7 @@ class MQTTClient(APITransport, Subscribable):
             transports=["http", "websocket", "internal"])
 
         # Subscribe to API requests
-        self.json_rpc = JsonRPC(transport="MQTT")
+        self.json_rpc = JsonRPC(self.server, transport="MQTT")
         self.api_request_topic = f"{self.instance_name}/moonraker/api/request"
         self.api_resp_topic = f"{self.instance_name}/moonraker/api/response"
         self.klipper_status_topic = f"{self.instance_name}/klipper/status"

moonraker/websockets.py

@@ -9,6 +9,7 @@ import logging
 import ipaddress
 import json
 import asyncio
+import copy
 from tornado.websocket import WebSocketHandler, WebSocketClosedError
 from utils import ServerError, SentinelClass
 
@@ -154,9 +155,48 @@ class WebRequest:
         return self._get_converted_arg(key, default, bool)
 
 class JsonRPC:
-    def __init__(self, transport: str = "Websocket") -> None:
+    def __init__(
+        self, server: Server, transport: str = "Websocket"
+    ) -> None:
         self.methods: Dict[str, RPCCallback] = {}
         self.transport = transport
+        self.sanitize_response = False
+        self.verbose = server.is_verbose_enabled()
+
+    def _log_request(self, rpc_obj: Dict[str, Any], ) -> None:
+        if not self.verbose:
+            return
+        self.sanitize_response = False
+        output = rpc_obj
+        method: Optional[str] = rpc_obj.get("method")
+        params: Dict[str, Any] = rpc_obj.get("params", {})
+        if isinstance(method, str):
+            if (
+                method.startswith("access.") or
+                method == "machine.sudo.password"
+            ):
+                self.sanitize_response = True
+                if params and isinstance(params, dict):
+                    output = copy.deepcopy(rpc_obj)
+                    output["params"] = {key: "<sanitized>" for key in params}
+            elif method == "server.connection.identify":
+                output = copy.deepcopy(rpc_obj)
+                for field in ["access_token", "api_key"]:
+                    if field in params:
+                        output["params"][field] = "<sanitized>"
+        logging.debug(f"{self.transport} Received::{json.dumps(output)}")
+
+    def _log_response(self, resp_obj: Optional[Dict[str, Any]]) -> None:
+        if not self.verbose:
+            return
+        if resp_obj is None:
+            return
+        output = resp_obj
+        if self.sanitize_response and "result" in resp_obj:
+            output = copy.deepcopy(resp_obj)
+            output["result"] = "<sanitized>"
+        self.sanitize_response = False
+        logging.debug(f"{self.transport} Response::{json.dumps(output)}")
 
     def register_method(self,
                         name: str,
@@ -171,29 +211,30 @@ class JsonRPC:
                        data: str,
                        conn: Optional[BaseSocketClient] = None
                        ) -> Optional[str]:
-        response: Any = None
         try:
             obj: Union[Dict[str, Any], List[dict]] = json.loads(data)
         except Exception:
             msg = f"{self.transport} data not json: {data}"
             logging.exception(msg)
-            response = self.build_error(-32700, "Parse error")
-            return json.dumps(response)
-        logging.debug(f"{self.transport} Received::{data}")
+            err = self.build_error(-32700, "Parse error")
+            return json.dumps(err)
         if isinstance(obj, list):
-            response = []
+            responses: List[Dict[str, Any]] = []
             for item in obj:
+                self._log_request(item)
                 resp = await self.process_object(item, conn)
                 if resp is not None:
-                    response.append(resp)
-            if not response:
-                response = None
+                    self._log_response(resp)
+                    responses.append(resp)
+            if responses:
+                return json.dumps(responses)
         else:
+            self._log_request(obj)
             response = await self.process_object(obj, conn)
             if response is not None:
-            response = json.dumps(response)
-            logging.debug(f"{self.transport} Response::{response}")
-        return response
+                self._log_response(response)
+                return json.dumps(response)
+        return None
 
     async def process_object(self,
                              obj: Dict[str, Any],
@@ -310,7 +351,7 @@ class WebsocketManager(APITransport):
         self.server = server
         self.klippy: Klippy = server.lookup_component("klippy_connection")
         self.clients: Dict[int, BaseSocketClient] = {}
-        self.rpc = JsonRPC()
+        self.rpc = JsonRPC(server)
         self.closed_event: Optional[asyncio.Event] = None
 
         self.rpc.register_method("server.websocket.id", self._handle_id_request)