From e93f85ae82c4c9862953968547e326a41a4c0699 Mon Sep 17 00:00:00 2001
From: Lin Yang <lin.a.yang@intel.com>
Date: Wed, 4 Jan 2017 16:13:45 -0800
Subject: [PATCH] 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                 | 20 ++++++++++++++++++--
 valence/api/v1/flavors.py          |  2 --
 valence/api/v1/nodes.py            |  5 -----
 valence/api/v1/storages.py         |  2 --
 valence/api/v1/systems.py          |  2 --
 valence/tests/unit/api/test_app.py |  2 +-
 6 files changed, 19 insertions(+), 14 deletions(-)

diff --git a/valence/api/app.py b/valence/api/app.py
index ea278b0..5b33746 100644
--- a/valence/api/app.py
+++ b/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
 
 
diff --git a/valence/api/v1/flavors.py b/valence/api/v1/flavors.py
index 9f78e98..37a2322 100644
--- a/valence/api/v1/flavors.py
+++ b/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())
diff --git a/valence/api/v1/nodes.py b/valence/api/v1/nodes.py
index 5c62b04..d7dba12 100644
--- a/valence/api/v1/nodes.py
+++ b/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)
diff --git a/valence/api/v1/storages.py b/valence/api/v1/storages.py
index 570d33b..50d5974 100644
--- a/valence/api/v1/storages.py
+++ b/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)
diff --git a/valence/api/v1/systems.py b/valence/api/v1/systems.py
index 1089ae2..d85ab42 100644
--- a/valence/api/v1/systems.py
+++ b/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)
diff --git a/valence/tests/unit/api/test_app.py b/valence/tests/unit/api/test_app.py
index 9bb4f0e..484b005 100644
--- a/valence/tests/unit/api/test_app.py
+++ b/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)