From 9c6b562e7bd2f2a9928c7d5a7563ec1d4646c7fa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Tue, 17 Oct 2017 11:40:41 +0200 Subject: [PATCH 1/7] Fixed Component.log() to include the date and [SDK] prefix --- CHANGELOG.md | 2 ++ katana/logging.py | 2 +- tests/api/test_base.py | 2 +- tests/sdk/test_component.py | 2 +- 4 files changed, 5 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b51e727..de81ed0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,8 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/) and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] +### Fixed +- Component.log() now includes the date and [SDK] prefix. ## [1.2.1] - 2017-10-01 ## Changed diff --git a/katana/logging.py b/katana/logging.py index 68afa11..f7c2b1b 100644 --- a/katana/logging.py +++ b/katana/logging.py @@ -107,7 +107,7 @@ def setup_katana_logging(level=logging.INFO): logger.setLevel(logging.DEBUG) if not logger.handlers: handler = logging.StreamHandler(stream=output) - handler.setFormatter(logging.Formatter()) # No format is applied + handler.setFormatter(KatanaFormatter(format)) logger.addHandler(handler) logger.propagate = False diff --git a/tests/api/test_base.py b/tests/api/test_base.py index 43e5a16..b905056 100644 --- a/tests/api/test_base.py +++ b/tests/api/test_base.py @@ -148,4 +148,4 @@ def test_api_base_log(mocker, logs): assert api.is_debug() api.log(log_message) out = logs.getvalue() - assert out.rstrip() == log_message + assert out.rstrip().endswith(log_message) diff --git a/tests/sdk/test_component.py b/tests/sdk/test_component.py index ad58085..da471b2 100644 --- a/tests/sdk/test_component.py +++ b/tests/sdk/test_component.py @@ -81,4 +81,4 @@ def test_component_log(logs): Component().log(expected) out = logs.getvalue() # Output without line break should match - assert out.rstrip() == expected + assert out.rstrip().endswith(expected) From 9372fc4dee50ce3aded9a7041102d2868dc08ee5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Tue, 17 Oct 2017 11:43:08 +0200 Subject: [PATCH 2/7] Added action tags support Issue #86 --- CHANGELOG.md | 3 +++ katana/api/schema/action.py | 24 ++++++++++++++++++++++++ katana/payload.py | 1 + tests/api/schema/test_schema_action.py | 8 ++++++++ tests/data/schema-service.json | 1 + 5 files changed, 37 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index de81ed0..4ee6319 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,9 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/) and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] +### Added +- Support for action tags defined in the configuration. + ### Fixed - Component.log() now includes the date and [SDK] prefix. diff --git a/katana/api/schema/action.py b/katana/api/schema/action.py index f687b03..8f024f1 100644 --- a/katana/api/schema/action.py +++ b/katana/api/schema/action.py @@ -101,6 +101,7 @@ def __init__(self, name, payload): self.__payload = Payload(payload) self.__params = self.__payload.get('params', {}) self.__files = self.__payload.get('files', {}) + self.__tags = self.__payload.get('tags', []) def is_deprecated(self): """Check if action has been deprecated. @@ -473,6 +474,29 @@ def get_file_schema(self, name): return FileSchema(name, self.__files[name]) + def has_tag(self, name): + """Check that a tag is defined for the action. + + The tag name is case sensitive. + + :param name: Tag name. + :type name: str + + :rtype: bool + + """ + + return name in self.__tags + + def get_tags(self): + """Get the tags defined for the action. + + :rtype: list + + """ + + return list(self.__tags) + def get_http_schema(self): """Get HTTP action schema. diff --git a/katana/payload.py b/katana/payload.py index f327566..77fa8cd 100644 --- a/katana/payload.py +++ b/katana/payload.py @@ -142,6 +142,7 @@ 'status': 's', 'swap': 's', 'system': 's', + 'tags': 't', 'terminate': 't', 'token': 't', 'total': 't', diff --git a/tests/api/schema/test_schema_action.py b/tests/api/schema/test_schema_action.py index b25b2ba..b0f3c1e 100644 --- a/tests/api/schema/test_schema_action.py +++ b/tests/api/schema/test_schema_action.py @@ -33,6 +33,8 @@ def test_api_schema_action_defaults(): assert action.get_remote_calls() == [] assert not action.has_return() assert action.get_return_type() == '' + assert action.get_tags() == [] + assert not action.has_tag('foo') assert action.get_params() == [] assert not action.has_param('foo') @@ -86,6 +88,12 @@ def test_api_schema_action(read_json): assert action.has_return() assert action.get_return_type() == payload.get('return/type') + # Check tags + tags = action.get_tags() + assert len(tags) == 2 + for tag in ['foo', 'bar']: + assert tag in tags + # Check relations assert action.has_relations() assert sorted(action.get_relations()) == [ diff --git a/tests/data/schema-service.json b/tests/data/schema-service.json index 75af1c2..d629e9c 100644 --- a/tests/data/schema-service.json +++ b/tests/data/schema-service.json @@ -13,6 +13,7 @@ "d": ":", "k": "pk", "c": true, + "t": ["foo", "bar"], "C": [["foo", "1.0", "dummy"], ["bar", "1.1", "dummy"]], "dc": [["foo", "1.0", "dummy"], ["bar", "1.1", "dummy"]], "rc": [["ktp://87.65.43.21:4321", "foo", "1.0", "dummy"]], From 6aaa2e70baa9ca7a2fa7deb2ca1ae49e479095a6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Sat, 11 Nov 2017 10:27:41 +0100 Subject: [PATCH 3/7] Changed runtime call default timeout to 10000 --- CHANGELOG.md | 3 +++ katana/api/action.py | 7 ++----- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4ee6319..8abc8e8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,9 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ### Added - Support for action tags defined in the configuration. +### Changed +- Runtime call default timeout to 10000 + ### Fixed - Component.log() now includes the date and [SDK] prefix. diff --git a/katana/api/action.py b/katana/api/action.py index 5af98a8..7adc4d9 100644 --- a/katana/api/action.py +++ b/katana/api/action.py @@ -198,7 +198,7 @@ def runtime_call(address, transport, action, callee, **kwargs): command = CommandPayload.new('runtime-call', 'service', args=args) - timeout = kwargs.get('timeout') or 1000 + timeout = kwargs.get('timeout') or 10000 channel = ipc(address) socket = CONTEXT.socket(zmq.REQ) try: @@ -1019,12 +1019,9 @@ def remote_call(self, address, service, version, action, **kwargs): 'version': version, 'action': action, 'caller': self.get_action_name(), + 'timeout': kwargs.get('timeout') or 1000, }) - timeout = kwargs.get('timeout') - if timeout: - payload.set('timeout', timeout) - params = kwargs.get('params') if params: payload.set('params', parse_params(params)) From 849d09950c98a95524e28390d3ca115ec442b2b6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Sat, 11 Nov 2017 10:29:39 +0100 Subject: [PATCH 4/7] Change param schema default value getter to return None by default --- CHANGELOG.md | 3 ++- katana/api/schema/param.py | 4 ++-- tests/api/schema/test_schema_param.py | 2 +- 3 files changed, 5 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 8abc8e8..61e9e83 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,7 +9,8 @@ and this project adheres to [Semantic Versioning](http://semver.org/). - Support for action tags defined in the configuration. ### Changed -- Runtime call default timeout to 10000 +- Runtime call default timeout to 10000. +- Parameter schema default value getter now returns None by default. ### Fixed - Component.log() now includes the date and [SDK] prefix. diff --git a/katana/api/schema/param.py b/katana/api/schema/param.py index 60f9245..61824bf 100644 --- a/katana/api/schema/param.py +++ b/katana/api/schema/param.py @@ -101,11 +101,11 @@ def has_default_value(self): def get_default_value(self): """Get default value for parameter. - :rtype: str + :rtype: object """ - return self.__payload.get('default_value', '') + return self.__payload.get('default_value', None) def is_required(self): """Check if parameter is required. diff --git a/tests/api/schema/test_schema_param.py b/tests/api/schema/test_schema_param.py index b688a53..c6a2429 100644 --- a/tests/api/schema/test_schema_param.py +++ b/tests/api/schema/test_schema_param.py @@ -15,7 +15,7 @@ def test_api_schema_param(read_json): assert schema.get_pattern() == '' assert not schema.allow_empty() assert not schema.has_default_value() - assert schema.get_default_value() == '' + assert schema.get_default_value() is None assert not schema.is_required() assert schema.get_items() == {} assert schema.get_max() == sys.maxsize From 8f515fa5a98432cb597d3b60dc35460de10e5ff7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Thu, 30 Nov 2017 12:58:03 +0100 Subject: [PATCH 5/7] Error payload handling during runtime calls --- CHANGELOG.md | 3 +++ katana/api/action.py | 2 ++ 2 files changed, 5 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 61e9e83..b291e94 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,9 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ### Added - Support for action tags defined in the configuration. +### Fixed +- Error payload handling during runtime calls + ### Changed - Runtime call default timeout to 10000. - Parameter schema default value getter now returns None by default. diff --git a/katana/api/action.py b/katana/api/action.py index 7adc4d9..febb144 100644 --- a/katana/api/action.py +++ b/katana/api/action.py @@ -229,6 +229,8 @@ def runtime_call(address, transport, action, callee, **kwargs): if payload.path_exists('error'): raise ApiError(payload.get('error/message')) + elif payload.path_exists('command_reply/result/error'): + raise ApiError(payload.get('command_reply/result/error/message')) result = payload.get('command_reply/result') return (get_path(result, 'transport'), get_path(result, 'return')) From 997cca49f1b0c5a7c74201c6d118c43167fbe37e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Fri, 1 Dec 2017 16:19:16 +0100 Subject: [PATCH 6/7] Component and framework info was added to log prefix Issue #89 --- CHANGELOG.md | 2 ++ katana/api/action.py | 6 ++++ katana/api/base.py | 12 +++----- katana/api/param.py | 4 --- katana/api/request.py | 12 ++++++-- katana/api/response.py | 10 +++++-- katana/api/schema/file.py | 3 -- katana/api/schema/param.py | 3 -- katana/logging.py | 59 ++++++++++++++++++++++++++++++++++++-- katana/middleware.py | 4 +++ katana/payload.py | 19 ++++++++++++ katana/sdk/runner.py | 20 ++++++++----- katana/server.py | 30 +++++++++++++------ katana/service.py | 4 +++ tests/api/test_action.py | 32 +++++++++++++++++++++ tests/api/test_base.py | 7 ----- tests/api/test_request.py | 33 +++++++++++++++++++++ tests/api/test_response.py | 32 +++++++++++++++++++++ tests/conftest.py | 2 +- tests/test_logging.py | 10 ++++--- 20 files changed, 251 insertions(+), 53 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b291e94..e211029 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,8 @@ and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] ### Added - Support for action tags defined in the configuration. +- Request ID to logs. +- Component and framework info was added to log prefix. ### Fixed - Error payload handling during runtime calls diff --git a/katana/api/action.py b/katana/api/action.py index febb144..8aac3d3 100644 --- a/katana/api/action.py +++ b/katana/api/action.py @@ -16,6 +16,7 @@ import zmq +from ..logging import RequestLogger from ..payload import CommandPayload from ..payload import ErrorPayload from ..payload import get_path @@ -249,6 +250,11 @@ def __init__(self, action, params, transport, *args, **kwargs): for param in params } + # Logging is only enabled when debug is True + if self.is_debug(): + rid = transport.get('meta/id') + self._logger = RequestLogger(rid, 'katana.api') + service = self.get_name() version = self.get_version() action_name = self.get_action_name() diff --git a/katana/api/base.py b/katana/api/base.py index e134768..3229dbc 100644 --- a/katana/api/base.py +++ b/katana/api/base.py @@ -37,12 +37,8 @@ def __init__(self, component, path, name, version, framework_version, **kw): self.__debug = kw.get('debug', False) self._schema = get_schema_registry() self._component = component - - # Logging is only enabled when debug is True - if self.__debug: - self.__logger = logging.getLogger('katana.api') - else: - self.__logger = None + # Logger must be initialized by child classes + self._logger = None def is_debug(self): """Determine if component is running in debug mode. @@ -213,8 +209,8 @@ def log(self, value): """ - if self.__logger: - self.__logger.debug(value_to_log_string(value)) + if self._logger: + self._logger.debug(value_to_log_string(value)) def done(self): """This method does nothing and returns False. diff --git a/katana/api/param.py b/katana/api/param.py index 5162eb3..cd9143e 100644 --- a/katana/api/param.py +++ b/katana/api/param.py @@ -9,16 +9,12 @@ file that was distributed with this source code. """ -import logging - from ..payload import get_path from ..payload import Payload __license__ = "MIT" __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" -LOG = logging.getLogger(__name__) - EMPTY = object() # Supported parameter types diff --git a/katana/api/request.py b/katana/api/request.py index 463e7cd..095cb9b 100644 --- a/katana/api/request.py +++ b/katana/api/request.py @@ -9,6 +9,11 @@ file that was distributed with this source code. """ +from .. import urn +from ..logging import RequestLogger +from ..payload import get_path +from ..payload import Payload + from .base import Api from .http.request import HttpRequest from .param import Param @@ -16,9 +21,6 @@ from .param import payload_to_param from .response import Response from .transport import Transport -from .. import urn -from ..payload import get_path -from ..payload import Payload __license__ = "MIT" __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" @@ -37,6 +39,10 @@ def __init__(self, *args, **kwargs): self.__gateway_protocol = kwargs.get('gateway_protocol') self.__gateway_addresses = kwargs.get('gateway_addresses') + # Logging is only enabled when debug is True + if self.is_debug(): + self._logger = RequestLogger(self.__request_id, 'katana.api') + http_request = kwargs.get('http_request') if http_request: self.__http_request = HttpRequest(**http_request) diff --git a/katana/api/response.py b/katana/api/response.py index 19d2334..c14a3a5 100644 --- a/katana/api/response.py +++ b/katana/api/response.py @@ -9,11 +9,12 @@ file that was distributed with this source code. """ +from ..errors import KatanaError +from ..logging import RequestLogger + from .base import Api -from .base import ApiError from .http.request import HttpRequest from .http.response import HttpResponse -from ..errors import KatanaError __license__ = "MIT" __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" @@ -38,6 +39,11 @@ def __init__(self, transport, *args, **kwargs): super().__init__(*args, **kwargs) self.__attributes = kwargs['attributes'] + # Logging is only enabled when debug is True + if self.is_debug(): + rid = transport.get_request_id() + self._logger = RequestLogger(rid, 'katana.api') + self.__gateway_protocol = kwargs.get('gateway_protocol') self.__gateway_addresses = kwargs.get('gateway_addresses') diff --git a/katana/api/schema/file.py b/katana/api/schema/file.py index 4ce0886..cd7abff 100644 --- a/katana/api/schema/file.py +++ b/katana/api/schema/file.py @@ -9,7 +9,6 @@ file that was distributed with this source code. """ -import logging import sys from ...payload import Payload @@ -17,8 +16,6 @@ __license__ = "MIT" __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" -LOG = logging.getLogger(__name__) - class FileSchema(object): """File parameter schema in the framework.""" diff --git a/katana/api/schema/param.py b/katana/api/schema/param.py index 61824bf..a82744e 100644 --- a/katana/api/schema/param.py +++ b/katana/api/schema/param.py @@ -9,7 +9,6 @@ file that was distributed with this source code. """ -import logging import sys from ...payload import Payload @@ -17,8 +16,6 @@ __license__ = "MIT" __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" -LOG = logging.getLogger(__name__) - class ParamSchema(object): """Parameter schema in the framework.""" diff --git a/katana/logging.py b/katana/logging.py index f7c2b1b..800dd1f 100644 --- a/katana/logging.py +++ b/katana/logging.py @@ -23,6 +23,55 @@ __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" +class RequestLogger(object): + """ + Logger for requests. + + It appends the request ID to all logging messages. + + """ + + def __init__(self, rid, name): + self.rid = rid + self.log = logging.getLogger(name) + + def debug(self, msg, *args, **kw): + if self.rid: + self.log.debug(msg + ' |{}|'.format(self.rid), *args, **kw) + else: + self.log.debug(msg, *args, **kw) + + def info(self, msg, *args, **kw): + if self.rid: + self.log.info(msg + ' |{}|'.format(self.rid), *args, **kw) + else: + self.log.info(msg, *args, **kw) + + def warning(self, msg, *args, **kw): + if self.rid: + self.log.warning(msg + ' |{}|'.format(self.rid), *args, **kw) + else: + self.log.warning(msg, *args, **kw) + + def error(self, msg, *args, **kw): + if self.rid: + self.log.error(msg + ' |{}|'.format(self.rid), *args, **kw) + else: + self.log.error(msg, *args, **kw) + + def critical(self, msg, *args, **kw): + if self.rid: + self.log.critical(msg + ' |{}|'.format(self.rid), *args, **kw) + else: + self.log.critical(msg, *args, **kw) + + def exception(self, msg, *args, **kw): + if self.rid: + self.log.exception(msg + ' |{}|'.format(self.rid), *args, **kw) + else: + self.log.exception(msg, *args, **kw) + + class KatanaFormatter(logging.Formatter): """Default KATANA logging formatter.""" @@ -75,14 +124,20 @@ def get_output_buffer(): return sys.stdout -def setup_katana_logging(level=logging.INFO): +def setup_katana_logging(type, name, version, framework, level=logging.INFO): """Initialize logging defaults for KATANA. + :param type: Component type. + :param name: Component name. + :param version: Component version. + :param framework: KATANA framework version. :param level: Logging level. Default: INFO. """ - format = "%(asctime)sZ [%(levelname)s] [SDK] %(message)s" + format = "%(asctime)sZ {} [%(levelname)s] [SDK] %(message)s".format( + "{} {}/{} ({})".format(type, name, version, framework) + ) output = get_output_buffer() diff --git a/katana/middleware.py b/katana/middleware.py index edc6c25..d2e9573 100644 --- a/katana/middleware.py +++ b/katana/middleware.py @@ -43,6 +43,10 @@ def __init__(self, *args, **kwargs): super().__init__(*args, **kwargs) self.__component = get_component() + @staticmethod + def get_type(): + return 'middleware' + @staticmethod def http_request_from_payload(payload): if not payload.path_exists('request'): diff --git a/katana/payload.py b/katana/payload.py index 77fa8cd..5e348d9 100644 --- a/katana/payload.py +++ b/katana/payload.py @@ -477,6 +477,25 @@ def new(cls, name, scope, args=None): return payload + @property + def request_id(self): + """ + Get current request ID from command arguments. + + The ID is available for request, response and action commands. + + :rtype: str + + """ + + # For request and response meta is an argument + rid = self.get('command/arguments/meta/id', '') + if not rid: + # For action payloads meta is part of the transport + rid = self.get('command/arguments/transport/meta/id', '') + + return rid + class CommandResultPayload(Payload): """Class definition for command result payloads.""" diff --git a/katana/sdk/runner.py b/katana/sdk/runner.py index 4a7254f..6c9930a 100644 --- a/katana/sdk/runner.py +++ b/katana/sdk/runner.py @@ -356,13 +356,6 @@ def run(self, **kwargs): # Add action name to message message['action'] = kwargs['action'] - # Initialize component logging only when `quiet` argument is False, or - # if an input message is given init logging only when debug is True - if not kwargs.get('quiet'): - setup_katana_logging(logging.DEBUG if self.debug else logging.INFO) - - LOG.debug('Using PID: "%s"', os.getpid()) - # Skip zeromq initialization when transport payload is given # as an input file in the CLI. if message: @@ -390,6 +383,19 @@ def run(self, **kwargs): error_callback=self.__error_callback, ) + # Initialize component logging only when `quiet` argument is False, or + # if an input message is given init logging only when debug is True + if not kwargs.get('quiet'): + setup_katana_logging( + self.server_cls.get_type(), + server.component_name, + server.component_version, + server.framework_version, + logging.DEBUG if self.debug else logging.INFO, + ) + + LOG.debug('Using PID: "%s"', os.getpid()) + if message: server_task = self.loop.create_task(server.process_input(message)) else: diff --git a/katana/server.py b/katana/server.py index a5365f1..5b724c2 100644 --- a/katana/server.py +++ b/katana/server.py @@ -20,6 +20,7 @@ from .errors import KatanaError from .json import serialize +from .logging import RequestLogger from .payload import CommandPayload from .payload import CommandResultPayload from .payload import ErrorPayload @@ -97,6 +98,17 @@ def __init__(self, callbacks, args, **kwargs): self.context = None self.poller = None + @staticmethod + def get_type(): + """ + Get the name of the component type. + + :rtype: str + + """ + + raise NotImplementedError() + @property def component_name(self): return self.__args['name'] @@ -203,18 +215,17 @@ def __update_schema_registry(self, stream): @asyncio.coroutine def __process_request_payload(self, action, payload): # Call request handler and send response back + cmd = CommandPayload(payload) try: - payload = yield from self.process_payload( - action, - CommandPayload(payload), - ) + payload = yield from self.process_payload(action, cmd) except asyncio.CancelledError: # Avoid logging task cancel errors by catching it here raise except KatanaError as err: payload = ErrorPayload.new(message=err.message).entity() except: - LOG.exception('Component failed') + rlog = RequestLogger(cmd.request_id, __name__) + rlog.exception('Component failed') payload = ErrorPayload.new('Component failed').entity() return payload @@ -275,7 +286,8 @@ def process_payload(self, action, payload): return ErrorPayload.new('Internal communication failed').entity() command_name = payload.get('command/name') - + # Create a request logger using the request ID from the command payload + rlog = RequestLogger(payload.request_id, __name__) # Create a variable to hold extra command reply result values. # This is used for example to the request attributes. # Because extra is passed by reference any modification by the @@ -311,18 +323,18 @@ def process_payload(self, action, payload): payload=payload, ) except Exception as exc: - LOG.exception('Component failed') + rlog.exception('Component failed') error = exc payload = ErrorPayload.new(str(exc)).entity() else: payload = self.component_to_payload(payload, component) if error and self.error_callback: - LOG.debug('Running error callback ...') + rlog.debug('Running error callback ...') try: self.error_callback(error) except: - LOG.exception('Error callback failed for "%s"', action) + rlog.exception('Error callback failed for "%s"', action) # Add extra command reply result values to payload if extra: diff --git a/katana/service.py b/katana/service.py index 6b5f1a8..5159c86 100644 --- a/katana/service.py +++ b/katana/service.py @@ -38,6 +38,10 @@ def __init__(self, *args, **kwargs): self.__return_value = None self.__transport = None + @staticmethod + def get_type(): + return 'service' + @property def component_path(self): return '{}/{}'.format( diff --git a/tests/api/test_action.py b/tests/api/test_action.py index 87c1be6..18a1279 100644 --- a/tests/api/test_action.py +++ b/tests/api/test_action.py @@ -15,6 +15,7 @@ from katana.payload import FIELD_MAPPINGS from katana.payload import get_path from katana.payload import Payload +from katana.schema import SchemaRegistry from katana.utils import nomap # Mapped parameter names for payload @@ -794,3 +795,34 @@ def test_api_action_errors(read_json, registry): assert len(errors) == 2 for error in errors: assert isinstance(error, ErrorPayload) + + +def test_action_log(mocker, logs, read_json): + SchemaRegistry() + + values = { + 'action': 'bar', + 'params': [], + 'transport': Payload(read_json('transport.json')), + 'component': None, + 'path': '/path/to/file.py', + 'name': 'test', + 'version': '1.0', + 'framework_version': '1.0.0', + } + action = Action(**values) + + log_message = 'Test log message' + # When debug is false no logging is done + assert not action.is_debug() + action.log(log_message) + out = logs.getvalue() + # There should be no ouput at all + assert len(out) == 0 + + # Create an instance with debug on + action = Action(debug=True, **values) + assert action.is_debug() + action.log(log_message) + out = logs.getvalue() + assert out.rstrip().split(' |')[0].endswith(log_message) diff --git a/tests/api/test_base.py b/tests/api/test_base.py index b905056..d7bf9ff 100644 --- a/tests/api/test_base.py +++ b/tests/api/test_base.py @@ -142,10 +142,3 @@ def test_api_base_log(mocker, logs): out = logs.getvalue() # There should be no ouput at all assert len(out) == 0 - - # Create an instance with debug on - api = base.Api(debug=True, **values) - assert api.is_debug() - api.log(log_message) - out = logs.getvalue() - assert out.rstrip().endswith(log_message) diff --git a/tests/api/test_request.py b/tests/api/test_request.py index ae678f4..f3b5cf8 100644 --- a/tests/api/test_request.py +++ b/tests/api/test_request.py @@ -162,3 +162,36 @@ def test_api_request_new_param(): # Check error when a parameter has inconsisten type and value with pytest.raises(TypeError): request.new_param('foo', value=True, type=TYPE_INTEGER) + + +def test_request_log(mocker, logs): + SchemaRegistry() + + values = { + 'attributes': {}, + 'component': object(), + 'request_id': 'TEST', + 'path': '/path/to/file.py', + 'name': 'dummy', + 'version': '1.0', + 'framework_version': '1.0.0', + 'client_address': '205.81.5.62:7681', + 'gateway_protocol': urn.HTTP, + 'gateway_addresses': ['12.34.56.78:1234', 'http://127.0.0.1:80'], + } + request = Request(**values) + + log_message = 'Test log message' + # When debug is false no logging is done + assert not request.is_debug() + request.log(log_message) + out = logs.getvalue() + # There should be no ouput at all + assert len(out) == 0 + + # Create an instance with debug on + request = Request(debug=True, **values) + assert request.is_debug() + request.log(log_message) + out = logs.getvalue() + assert out.rstrip().split(' |')[0].endswith(log_message) diff --git a/tests/api/test_response.py b/tests/api/test_response.py index 42703ca..1fb9392 100644 --- a/tests/api/test_response.py +++ b/tests/api/test_response.py @@ -41,3 +41,35 @@ def test_api_response(): response = Response(**values) assert isinstance(response.get_http_request(), HttpRequest) assert isinstance(response.get_http_response(), HttpResponse) + + +def test_response_log(mocker, logs): + SchemaRegistry() + + values = { + 'attributes': {}, + 'transport': Transport({'meta': {'id': 'TEST'}}), + 'component': object(), + 'path': '/path/to/file.py', + 'name': 'dummy', + 'version': '1.0', + 'framework_version': '1.0.0', + 'gateway_protocol': urn.HTTP, + 'gateway_addresses': ['12.34.56.78:1234', 'http://127.0.0.1:80'], + } + response = Response(**values) + + log_message = 'Test log message' + # When debug is false no logging is done + assert not response.is_debug() + response.log(log_message) + out = logs.getvalue() + # There should be no ouput at all + assert len(out) == 0 + + # Create an instance with debug on + response = Response(debug=True, **values) + assert response.is_debug() + response.log(log_message) + out = logs.getvalue() + assert out.rstrip().split(' |')[0].endswith(log_message) diff --git a/tests/conftest.py b/tests/conftest.py index 0fc8b31..abd46f6 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -89,7 +89,7 @@ def cleanup(): request.addfinalizer(cleanup) mocker.patch('katana.logging.get_output_buffer', return_value=output) - setup_katana_logging() + setup_katana_logging('component', 'name', 'version', 'framework-version') return output diff --git a/tests/test_logging.py b/tests/test_logging.py index 2c32fd4..0dc2d1f 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -1,7 +1,6 @@ import logging from katana.logging import KatanaFormatter -from katana.logging import setup_katana_logging from katana.logging import value_to_log_string @@ -70,6 +69,9 @@ def test_setup_katana_logging(logs): assert len(out) > 0 out_parts = out.split(' ') assert out_parts[0].endswith('Z') # Time - assert out_parts[1] == '[INFO]' # Level - assert out_parts[2] == '[SDK]' # SDK prefix - assert ' '.join(out_parts[3:]).strip() == message + assert out_parts[1] == 'component' # Component type + assert out_parts[2] == 'name/version' # Component name and version + assert out_parts[3] == '(framework-version)' + assert out_parts[4] == '[INFO]' # Level + assert out_parts[5] == '[SDK]' # SDK prefix + assert ' '.join(out_parts[6:]).strip() == message From e92f43d3c685872e032016a3f3a1406d1e0c0de1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jero=CC=81nimo=20Albi?= Date: Fri, 1 Dec 2017 16:28:19 +0100 Subject: [PATCH 7/7] Updated version to 1.3.0 --- CHANGELOG.md | 2 ++ katana/__init__.py | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index e211029..ad9d015 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,8 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/) and this project adheres to [Semantic Versioning](http://semver.org/). ## [Unreleased] + +## [1.3.0] - 2017-11-01 ### Added - Support for action tags defined in the configuration. - Request ID to logs. diff --git a/katana/__init__.py b/katana/__init__.py index e68cb0f..e30f188 100644 --- a/katana/__init__.py +++ b/katana/__init__.py @@ -12,4 +12,4 @@ __license__ = "MIT" __copyright__ = "Copyright (c) 2016-2017 KUSANAGI S.L. (http://kusanagi.io)" -__version__ = '1.2.1' +__version__ = '1.3.0'