Mask secrets when logging in json_rpc

Otherwise passwords are displayed in plain text in the DEBUG logs.

Change-Id: I4210492bc7cb42b205d2b93a018bfaa25bfe5752
Story: #2006744
Task: #37216
(cherry picked from commit 3ab93f0c84a5a8e2551f31c7f6ea24fc62ae79a9)

4 files changed, 63 insertions, 4 deletions

diff --git a/ironic/common/json_rpc/client.py b/ironic/common/json_rpc/client.py
index c524c43f4..b6692d901 100644
--- a/ironic/common/json_rpc/client.py
+++ b/ironic/common/json_rpc/client.py
@@ -18,6 +18,7 @@ This client is compatible with any JSON RPC 2.0 implementation, including ours.
 from oslo_config import cfg
 from oslo_log import log
 from oslo_utils import importutils
+from oslo_utils import strutils
 from oslo_utils import uuidutils
 
 from ironic.common import exception
@@ -151,10 +152,11 @@ class _CallContext(object):
         if not cast:
             body['id'] = context.request_id or uuidutils.generate_uuid()
 
-        LOG.debug("RPC %s with %s", method, body)
+        LOG.debug("RPC %s with %s", method, strutils.mask_dict_password(body))
         url = 'http://%s:%d' % (self.host, CONF.json_rpc.port)
         result = _get_session().post(url, json=body)
-        LOG.debug('RPC %s returned %s', method, result.text or '<None>')
+        LOG.debug('RPC %s returned %s', method,
+                  strutils.mask_password(result.text or '<None>'))
 
         if not cast:
             result = result.json()
diff --git a/ironic/common/json_rpc/server.py b/ironic/common/json_rpc/server.py
index 3d9fe6ef1..39fb67be0 100644
--- a/ironic/common/json_rpc/server.py
+++ b/ironic/common/json_rpc/server.py
@@ -27,6 +27,7 @@ from oslo_log import log
 import oslo_messaging
 from oslo_service import service
 from oslo_service import wsgi
+from oslo_utils import strutils
 import webob
 
 from ironic.common import context as ir_context
@@ -222,6 +223,7 @@ class WSGIService(service.Service):
         """
         # TODO(dtantsur): server-side version check?
         params.pop('rpc.version', None)
+        logged_params = strutils.mask_dict_password(params)
 
         try:
             context = params.pop('context')
@@ -238,7 +240,7 @@ class WSGIService(service.Service):
                       for key, value in params.items()}
             params['context'] = context
 
-        LOG.debug('RPC %s with %s', name, params)
+        LOG.debug('RPC %s with %s', name, logged_params)
         try:
             result = func(**params)
         # FIXME(dtantsur): we could use the inspect module, but
@@ -251,7 +253,9 @@ class WSGIService(service.Service):
             # Currently it seems that we can serialize even with invalid
             # context, but I'm not sure it's guaranteed to be the case.
             result = self.serializer.serialize_entity(context, result)
-        LOG.debug('RPC %s returned %s', name, result)
+        LOG.debug('RPC %s returned %s', name,
+                  strutils.mask_dict_password(result)
+                  if isinstance(result, dict) else result)
         return result
 
     def start(self):
diff --git a/ironic/tests/unit/common/test_json_rpc.py b/ironic/tests/unit/common/test_json_rpc.py
index 082eaa0a0..2c6207f3b 100644
--- a/ironic/tests/unit/common/test_json_rpc.py
+++ b/ironic/tests/unit/common/test_json_rpc.py
@@ -22,6 +22,7 @@ from ironic.common.json_rpc import server
 from ironic import objects
 from ironic.objects import base as objects_base
 from ironic.tests import base as test_base
+from ironic.tests.unit.db import utils as db_utils
 from ironic.tests.unit.objects import utils as obj_utils
 
 
@@ -266,6 +267,22 @@ class TestService(test_base.TestCase):
         self._request('success', {'context': self.ctx, 'x': 42},
                       expected_error=403)
 
+    @mock.patch.object(server.LOG, 'debug', autospec=True)
+    def test_mask_secrets(self, mock_log):
+        node = obj_utils.get_test_node(
+            self.context, driver_info=db_utils.get_test_ipmi_info())
+        node = self.serializer.serialize_entity(self.context, node)
+        body = self._request('with_node', {'context': self.ctx, 'node': node})
+        node = self.serializer.deserialize_entity(self.context, body['result'])
+        logged_params = mock_log.call_args_list[0][0][2]
+        logged_node = logged_params['node']['ironic_object.data']
+        self.assertEqual('***', logged_node['driver_info']['ipmi_password'])
+        logged_resp = mock_log.call_args_list[1][0][2]
+        logged_node = logged_resp['ironic_object.data']
+        self.assertEqual('***', logged_node['driver_info']['ipmi_password'])
+        # The result is not affected, only logging
+        self.assertEqual(db_utils.get_test_ipmi_info(), node.driver_info)
+
 
 @mock.patch.object(client, '_get_session', autospec=True)
 class TestClient(test_base.TestCase):
@@ -493,3 +510,34 @@ class TestClient(test_base.TestCase):
                                cctx.call, self.context, 'do_something',
                                answer=42)
         self.assertFalse(mock_session.return_value.post.called)
+
+    @mock.patch.object(client.LOG, 'debug', autospec=True)
+    def test_mask_secrets(self, mock_log, mock_session):
+        request = {
+            'redfish_username': 'admin',
+            'redfish_password': 'passw0rd'
+        }
+        body = """{
+            "jsonrpc": "2.0",
+            "result": {
+                "driver_info": {
+                    "ipmi_username": "admin",
+                    "ipmi_password": "passw0rd"
+                }
+            }
+        }"""
+        response = mock_session.return_value.post.return_value
+        response.text = body
+        cctx = self.client.prepare('foo.example.com')
+        cctx.cast(self.context, 'do_something', node=request)
+        mock_session.return_value.post.assert_called_once_with(
+            'http://example.com:8089',
+            json={'jsonrpc': '2.0',
+                  'method': 'do_something',
+                  'params': {'node': request, 'context': self.ctx_json}})
+        self.assertEqual(2, mock_log.call_count)
+        node = mock_log.call_args_list[0][0][2]['params']['node']
+        self.assertEqual(node, {'redfish_username': 'admin',
+                                'redfish_password': '***'})
+        resp_text = mock_log.call_args_list[1][0][2]
+        self.assertEqual(body.replace('passw0rd', '***'), resp_text)
diff --git a/releasenotes/notes/jsonrpc-logging-21670015bb845182.yaml b/releasenotes/notes/jsonrpc-logging-21670015bb845182.yaml
new file mode 100644
index 000000000..c23d9cdee
--- /dev/null
+++ b/releasenotes/notes/jsonrpc-logging-21670015bb845182.yaml
@@ -0,0 +1,5 @@
+---
+security:
+  - |
+    Node secrets (such as BMC credentials) are no longer logged when JSON RPC
+    is used and DEBUG logging is enabled.