Log every flask request and response for debug

Added two functions with flask before/after_request decorator to log
headers and content for every request and response.

Change-Id: I8bae4cfd485c49e6fd149a3df5695c94e806264b
Closes-Bug: #1654036

valence/api/app.py

@@ -15,7 +15,7 @@ import os.path
 
 from logging.handlers import RotatingFileHandler
 
-from flask import Flask
+import flask
 
 from valence import config as cfg
 
@@ -24,7 +24,7 @@ _app = None
 
 def setup_app():
     """Return Flask application"""
-    app = Flask(cfg.PROJECT_NAME)
+    app = flask.Flask(cfg.PROJECT_NAME)
     app.url_map.strict_slashes = False
     TEN_KB = 10 * 1024
 
@@ -37,6 +37,22 @@ def setup_app():
         handler.setFormatter(formatter)
         app.logger.addHandler(handler)
     app.logger.setLevel(cfg.log_level)
+
+    @app.before_request
+    def before_request_logging():
+        req = flask.request
+        app.logger.debug('{0} {1}'.format(req.method, req.url))
+        app.logger.debug('Request Headers: {0}'.format(dict(req.headers)))
+        if req.data:
+            app.logger.debug('Request Content: {0}'.format(req.data))
+
+    @app.after_request
+    def after_request_logging(resp):
+        app.logger.debug('Response Headers: {0}'.format(dict(resp.headers)))
+        if resp.data:
+            app.logger.debug('Response Content: {0}'.format(resp.data))
+        return resp
+
     return app
 
 

valence/api/v1/flavors.py

@@ -25,9 +25,7 @@ LOG = logging.getLogger(__name__)
 class Flavors(Resource):
 
     def get(self):
-        LOG.debug("GET /flavors")
         return flavors.get_available_criteria()
 
     def post(self):
-        LOG.debug("POST /flavors")
         return flavors.create_flavors(request.get_json())

valence/api/v1/nodes.py

@@ -26,27 +26,22 @@ LOG = logging.getLogger(__name__)
 class NodesList(Resource):
 
     def get(self):
-        LOG.debug("GET /nodes")
         return redfish.nodes_list(request.args)
 
     def post(self):
-        LOG.debug("POST /nodes/")
         return redfish.compose_node(request.get_json())
 
 
 class Nodes(Resource):
 
     def get(self, nodeid):
-        LOG.debug("GET /nodes/" + nodeid)
         return redfish.get_nodebyid(nodeid)
 
     def delete(self, nodeid):
-        LOG.debug("DELETE /nodes/" + nodeid)
         return redfish.delete_composednode(nodeid)
 
 
 class NodesStorage(Resource):
 
     def get(self, nodeid):
-        LOG.debug("GET /nodes/%s/storage" % nodeid)
         return abort(501)

valence/api/v1/storages.py

@@ -23,12 +23,10 @@ LOG = logging.getLogger(__name__)
 class StoragesList(Resource):
 
     def get(self):
-        LOG.debug("GET /storages")
         return abort(501)
 
 
 class Storages(Resource):
 
     def get(self, storageid):
-        LOG.debug("GET /storages" + storageid)
         return abort(501)

valence/api/v1/systems.py

@@ -25,12 +25,10 @@ LOG = logging.getLogger(__name__)
 class SystemsList(Resource):
 
     def get(self):
-        LOG.debug("GET /systems")
         return redfish.systems_list(request.args)
 
 
 class Systems(Resource):
 
     def get(self, systemid):
-        LOG.debug("GET /systems/" + systemid)
         return redfish.get_systembyid(systemid)

valence/tests/unit/api/test_app.py

@@ -21,7 +21,7 @@ from valence.api import app
 class TestApp(unittest.TestCase):
 
     @mock.patch('valence.config.PROJECT_NAME')
-    @mock.patch('valence.api.app.Flask')
+    @mock.patch('valence.api.app.flask.Flask')
     def test_setup_app_success(self, mock_Flask, mock_PROJECT_NAME):
         self.app = app.setup_app()
         mock_Flask.assert_called_with(mock_PROJECT_NAME)