Enable logging support in python sdk

openapiart/common.py

@@ -89,7 +89,7 @@ def __init__(self, **kwargs):
         self.loglevel = kwargs["loglevel"] if "loglevel" in kwargs else logging.DEBUG
         if self.logger is None:
             stdout_handler = logging.StreamHandler(sys.stdout)
-            formatter = logging.Formatter(fmt="%(asctime)s [%(name)s] [%(levelname)s] %(message)s", datefmt="%Y-%m-%d %H:%M:%S")
+            formatter = logging.Formatter(fmt="%(asctime)-8s %(levelname)-8s %(message)s", datefmt="%Y-%m-%d %H:%M:%S")
             formatter.converter = time.gmtime
             stdout_handler.setFormatter(formatter)
             self.logger = logging.Logger(self.__module__, level=self.loglevel)
@@ -118,6 +118,7 @@ def send_recv(self, method, relative_url, payload=None, return_object=None, head
                 data = payload.serialize()
             else:
                 raise Exception("Type of payload provided is unknown")
+        self.logger.debug("Request call: Method: {} ; url: {} ; payload: {}".format(method.upper(), url, data))
         response = self._session.request(
             method=method,
             url=url,
@@ -127,6 +128,7 @@ def send_recv(self, method, relative_url, payload=None, return_object=None, head
             # TODO: add a timeout here
             headers=headers,
         )
+        self.logger.debug('Response: Status code: {} ; Error: {}'.format(response.status_code, response.reason))
         if response.ok:
             if "application/json" in response.headers["content-type"]:
                 # TODO: we might want to check for utf-8 charset and decode
@@ -135,16 +137,20 @@ def send_recv(self, method, relative_url, payload=None, return_object=None, head
                 if return_object is None:
                     # if response type is not provided, return dictionary
                     # instead of python object
+                    self.logger.debug("Response data: {}".format(response_dict))
                     return response_dict
                 else:
+                    self.logger.debug("Response data: {}".format(return_object.deserialize(response_dict)))
                     return return_object.deserialize(response_dict)
             elif "application/octet-stream" in response.headers["content-type"]:
+                self.logger.debug("Response data: {}".format(io.BytesIO(response.content)))
                 return io.BytesIO(response.content)
             else:
                 # TODO: for now, return bare response object for unknown
                 # content types
                 return response
         else:
+            self.logger.error('Response: Status code: {} ; reason: {} ; data: {}'.format(response.status_code, response.reason, response.text))
             raise Exception(response.status_code, yaml.safe_load(response.text))
 
 
@@ -155,10 +161,10 @@ class OpenApiBase(object):
     YAML = "yaml"
     DICT = "dict"
 
-    __slots__ = ()
+    __slots__ = ("logger")
 
     def __init__(self):
-        pass
+        self.logger = logging.getLogger(self.__module__)
 
     def serialize(self, encoding=JSON):
         """Serialize the current object according to a specified encoding.

openapiart/generator.py

@@ -363,7 +363,7 @@ def __init__(self, **kwargs):
         self._loglevel = kwargs["loglevel"] if "loglevel" in kwargs else logging.DEBUG
         if self._logger is None:
             stdout_handler = logging.StreamHandler(sys.stdout)
-            formatter = logging.Formatter(fmt="%(asctime)s [%(name)s] [%(levelname)s] %(message)s", datefmt="%Y-%m-%d %H:%M:%S")
+            formatter = logging.Formatter(fmt="%(asctime)-8s %(levelname)-8s %(message)s", datefmt="%Y-%m-%d %H:%M:%S")
             formatter.converter = time.gmtime
             stdout_handler.setFormatter(formatter)
             self._logger = logging.Logger(self.__module__, level=self._loglevel)
@@ -433,6 +433,12 @@ def close(self):
                     self._write(
                         1, "def %s(self, payload):" % rpc_method.method
                     )
+                    self._write(
+                        2,
+                        """self._logger.debug("Calling method: {}")""".format(
+                            rpc_method.method
+                        ),
+                    )
                     self._write(2, "pb_obj = json_format.Parse(")
                     self._write(3, "self._serialize_payload(payload),")
                     self._write(3, "pb2.%s()" % rpc_method.request_class)
@@ -445,6 +451,10 @@ def close(self):
                             request_property=rpc_method.request_property,
                         ),
                     )
+                    self._write(
+                        2,
+                        """self._logger.debug("Request data: {}".format(req_obj))""",
+                    )
                     self._write(2, "stub = self._get_stub()")
                     self._write(
                         2,
@@ -457,11 +467,19 @@ def close(self):
                 self._write(2, "response = json_format.MessageToDict(")
                 self._write(3, "res_obj, preserving_proto_field_name=True")
                 self._write(2, ")")
+                self._write(
+                    2,
+                    """self._logger.debug("Response data: {}".format(response))""",
+                )
                 self._write(
                     2, 'status_code_200 = response.get("status_code_200")'
                 )
                 self._write(2, "if status_code_200 is not None:")
                 if return_byte:
+                    self._write(
+                        3,
+                        """self._logger.debug("Response data: {}".format(io.BytesIO(res_obj.status_code_200)))""",
+                    )
                     self._write(
                         3, "return io.BytesIO(res_obj.status_code_200)"
                     )
@@ -483,6 +501,10 @@ def close(self):
                     self._write(4, "status_code_200")
                     self._write(3, ")")
                 else:
+                    self._write(
+                        3,
+                        """self._logger.debug("Response data: {}".format(response.get("status_code_200")))""",
+                    )
                     self._write(3, 'return response.get("status_code_200")')
                 for rsp_code in rpc_method.bad_responses:
                     self._write(
@@ -491,6 +513,16 @@ def close(self):
                             code=rsp_code
                         ),
                     )
+                    self._write(
+                        3,
+                        """resp_code = response.get("status_code_{code}")""".format(
+                            code=rsp_code
+                        ),
+                    )
+                    self._write(
+                        3,
+                        """self._logger.error("response: {}".format(resp_code))""",
+                    )
                     self._write(
                         3,
                         """raise Exception({code}, response.get("status_code_{code}"))""".format(
@@ -570,7 +602,12 @@ def _write_http_api_class(self, methods):
                 self._write(0)
                 self._write(2, "Return: %s" % method["response_type"])
                 self._write(2, '"""')
-
+                self._write(
+                    2,
+                    """self.logger.debug("Calling method: {}")""".format(
+                        method["name"]
+                    ),
+                )
                 self._write(2, "return self._transport.send_recv(")
                 self._write(3, '"%s",' % method["http_method"])
                 self._write(3, '"%s",' % method["url"])
@@ -604,7 +641,26 @@ def _write_api_class(self, methods, factories):
             self._write(1, '"""')
             self._write()
             self._write(1, "def __init__(self, **kwargs):")
-            self._write(2, "pass")
+            self._write(
+                2,
+                'self.logger = kwargs["logger"] if "logger" in kwargs else None',
+            )
+            self._write(
+                2,
+                'self.loglevel = kwargs["loglevel"] if "loglevel" in kwargs else logging.INFO',
+            )
+            self._write(2, "if self.logger is None:")
+            self._write(3, "self.logger = logging.getLogger(self.__module__)")
+            self._write(3, "self.logger.setLevel(self.loglevel)")
+            self._write(
+                3,
+                'formatter = logging.Formatter(fmt="%(asctime)-8s %(levelname)-8s %(message)s", datefmt="%Y-%m-%d %H:%M:%S")',
+            )
+            self._write(3, "sh = logging.StreamHandler(sys.stdout)")
+            self._write(3, "sh.setFormatter(formatter)")
+            self._write(3, "if len(self.logger.handlers) > 0:")
+            self._write(4, "del self.logger.handlers[:]")
+            self._write(3, "self.logger.addHandler(sh)")
 
             for method in methods:
                 print("generating method %s" % method["name"])
@@ -1424,6 +1480,11 @@ def _write_data_properties(self, schema, classname, choice_tuples):
                 2,
                 "if isinstance(choice, (%s)) is False:" % (", ".join(choices)),
             )
+            self._write(
+                3,
+                """self.logger.error('choice must be of type: %s')"""
+                % (", ".join(choices)),
+            )
             self._write(
                 3,
                 "raise TypeError('choice must be of type: %s')"
@@ -1470,6 +1531,11 @@ def _write_data_properties(self, schema, classname, choice_tuples):
                             )
                         self._write(3, "self.%s = %s" % (name, name))
                     self._write(2, "else:")
+                    self._write(
+                        3,
+                        """self.logger.error(''%s must be an instance of %s')"""
+                        % (name, restriction),
+                    )
                     self._write(
                         3,
                         "raise TypeError('%s must be an instance of %s')"

openapiart/tests/test_log.py

@@ -0,0 +1,36 @@
+import json
+import sys
+import os
+from .server import app
+
+sys.path.append(os.path.join(os.path.dirname(__file__), "..", "..", "art"))
+import sanity
+
+
+def test_log_info():
+    api = sanity.api("http://127.0.0.1:{}".format(app.PORT))
+    config = api.prefix_config()
+    config.a = "asdf"
+    config.b = 1.1
+    config.c = 1
+    config.required_object.e_a = 1.1
+    config.required_object.e_b = 1.2
+    config.d_values = [config.A, config.B, config.C]
+    api.set_config(config)
+
+
+def test_log(api):
+    config = api.prefix_config()
+    config.a = "asdf"
+    config.b = 1.1
+    config.c = 1
+    config.required_object.e_a = 1.1
+    config.required_object.e_b = 1.2
+    config.d_values = [config.A, config.B, config.C]
+    api.set_config(config)
+
+
+def test_grpc_log(utils, grpc_api):
+    with open(utils.get_test_config_path("config.json")) as f:
+        payload = json.load(f)
+    grpc_api.set_config(payload)