Fix osdf code after upgrading to py38

Fix osdf logging to work with 3.8
Fix osdf code that broke after migration
Fix test cases after migration
Fixing pep8 violations

Change-Id: I11ca33959882c8b9010f00ff744d59c7eeb3c2f2
Signed-off-by: vrvarma <vikas.varma@att.com>
Issue-ID: OPTFRA-796

1 files changed, 81 insertions, 26 deletions

diff --git a/osdf/apps/baseapp.py b/osdf/apps/baseapp.py
index fa301d8..c4fc82d 100644
--- a/osdf/apps/baseapp.py
+++ b/osdf/apps/baseapp.py
@@ -21,24 +21,35 @@ OSDF Manager Main Flask Application
 """
 
 import json
+from optparse import OptionParser
 import ssl
 import sys
 import time
 import traceback
-from optparse import OptionParser
 
+from flask import Flask
+from flask import g
+from flask import request
+from flask import Response
+from onaplogging.mdcContext import MDC
 import pydevd
-from flask import Flask, request, Response, g
 from requests import RequestException
 from schematics.exceptions import DataError
 
 import osdf.adapters.aaf.sms as sms
-import osdf.operation.responses
 from osdf.config.base import osdf_config
-from osdf.logging.osdf_logging import error_log, debug_log
-from osdf.operation.error_handling import request_exception_to_json_body, internal_error_message
+from osdf.logging.osdf_logging import audit_log
+from osdf.logging.osdf_logging import debug_log
+from osdf.logging.osdf_logging import error_log
+from osdf.operation.error_handling import internal_error_message
+from osdf.operation.error_handling import request_exception_to_json_body
 from osdf.operation.exceptions import BusinessException
-from osdf.utils.mdc_utils import clear_mdc, mdc_from_json, default_mdc, get_request_id
+import osdf.operation.responses
+from osdf.utils.mdc_utils import clear_mdc
+from osdf.utils.mdc_utils import get_request_id
+from osdf.utils.mdc_utils import populate_default_mdc
+from osdf.utils.mdc_utils import populate_mdc
+from osdf.utils.mdc_utils import set_error_details
 
 ERROR_TEMPLATE = osdf.ERROR_TEMPLATE
 
@@ -49,8 +60,11 @@ BAD_CLIENT_REQUEST_MESSAGE = 'Client sent an invalid request'
 
 @app.errorhandler(BusinessException)
 def handle_business_exception(e):
-    """An exception explicitly raised due to some business rule"""
-    error_log.error("Synchronous error for request id {} {}".format(g.request_id, traceback.format_exc()))
+    """An exception explicitly raised due to some business rule
+
+    """
+    error_log.error("Synchronous error for request id {} {}"
+                    .format(g.request_id, traceback.format_exc()))
     err_msg = ERROR_TEMPLATE.render(description=str(e))
     response = Response(err_msg, content_type='application/json; charset=utf-8')
     response.status_code = 400
@@ -59,8 +73,9 @@ def handle_business_exception(e):
 
 @app.errorhandler(RequestException)
 def handle_request_exception(e):
-    """Returns a detailed synchronous message to the calling client
-    when osdf fails due to a remote call to another system"""
+    """Returns a detailed synchronous message to the calling client when osdf fails due to a remote call to another system
+
+    """
     error_log.error("Synchronous error for request id {} {}".format(g.request_id, traceback.format_exc()))
     err_msg = request_exception_to_json_body(e)
     response = Response(err_msg, content_type='application/json; charset=utf-8')
@@ -70,7 +85,9 @@ def handle_request_exception(e):
 
 @app.errorhandler(DataError)
 def handle_data_error(e):
-    """Returns a detailed message to the calling client when the initial synchronous message is invalid"""
+    """Returns a detailed message to the calling client when the initial synchronous message is invalid
+
+    """
     error_log.error("Synchronous error for request id {} {}".format(g.request_id, traceback.format_exc()))
 
     body_dictionary = {
@@ -89,29 +106,65 @@ def handle_data_error(e):
 
 @app.before_request
 def log_request():
-    g.request_start = time.process_time()
-    if request.data:
-        if request.get_json():
-            request_json = request.get_json()
-            g.request_id = get_request_id(request_json)
-            mdc_from_json(request_json)
-        else:
-            g.request_id = "N/A"
-            default_mdc()
+    clear_mdc()
+    if request.content_type and 'json' in request.content_type:
+        populate_mdc(request)
+        g.request_id = get_request_id(request.get_json())
+        log_message(json.dumps(request.get_json()), "INPROGRESS", 'ENTRY')
     else:
-        g.request_id = "N/A"
-        default_mdc()
+        populate_default_mdc(request)
+        log_message('', "INPROGRESS", 'ENTRY')
 
 
 @app.after_request
 def log_response(response):
-    clear_mdc()
+    log_response_data(response)
     return response
 
 
+def log_response_data(response):
+    status_value = ''
+    try:
+        status_value = map_status_value(response)
+        log_message(response.get_data(as_text=True), status_value, 'EXIT')
+    except Exception:
+        try:
+            set_default_audit_mdc(request, status_value, 'EXIT')
+            audit_log.info(response.get_data(as_text=True))
+        except Exception:
+            set_error_details(300, 'Internal Error')
+            error_log.error("Error logging the response data due to {}".format(traceback.format_exc()))
+
+
+def set_default_audit_mdc(request, status_value, p_marker):
+    MDC.put('partnerName', 'internal')
+    MDC.put('serviceName', request.path)
+    MDC.put('statusCode', status_value)
+    MDC.put('requestID', 'internal')
+    MDC.put('timer', int((time.process_time() - g.request_start) * 1000))
+    MDC.put('customField1', p_marker)
+
+
+def log_message(message, status_value, p_marker='INVOKE'):
+    MDC.put('statusCode', status_value)
+    MDC.put('customField1', p_marker)
+    MDC.put('timer', int((time.process_time() - g.request_start) * 1000))
+    audit_log.info(message)
+
+
+def map_status_value(response):
+    if 200 <= response.status_code < 300:
+        status_value = "COMPLETE"
+    else:
+        status_value = "ERROR"
+    return status_value
+
+
 @app.errorhandler(500)
 def internal_failure(error):
-    """Returned when unexpected coding errors occur during initial synchronous processing"""
+    """Returned when unexpected coding errors occur during initial synchronous processing
+
+    """
     error_log.error("Synchronous error for request id {} {}".format(g.request_id, traceback.format_exc()))
     response = Response(internal_error_message, content_type='application/json; charset=utf-8')
     response.status_code = 500
@@ -127,8 +180,10 @@ def get_options(argv):
     parser.add_option("-l", "--local", dest="local", help="run locally", action="store_true", default=False)
     parser.add_option("-t", "--devtest", dest="devtest", help="run in dev/test environment", action="store_true",
                       default=False)
-    parser.add_option("-d", "--debughost", dest="debughost", help="IP Address of host running debug server", default='')
-    parser.add_option("-p", "--debugport", dest="debugport", help="Port number of debug server", type=int, default=5678)
+    parser.add_option("-d", "--debughost", dest="debughost",
+                      help="IP Address of host running debug server", default='')
+    parser.add_option("-p", "--debugport", dest="debugport",
+                      help="Port number of debug server", type=int, default=5678)
     opts, args = parser.parse_args(argv)
 
     if opts.debughost: