diff --git a/openapiart/common.py b/openapiart/common.py index e40061f1..b80b21f8 100644 --- a/openapiart/common.py +++ b/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. diff --git a/openapiart/generator.py b/openapiart/generator.py index 67a4f54d..56bde7d5 100644 --- a/openapiart/generator.py +++ b/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')" diff --git a/openapiart/tests/test_log.py b/openapiart/tests/test_log.py new file mode 100644 index 00000000..507f567d --- /dev/null +++ b/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)