Repository: incubator-ariatosca Updated Branches: refs/heads/ARIA-106-Create-sqla-logging-handler d868713c4 -> 51b17799f
added basic logging mechanism for ops and wf Project: http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/repo Commit: http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/commit/2286b0dd Tree: http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/tree/2286b0dd Diff: http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/diff/2286b0dd Branch: refs/heads/ARIA-106-Create-sqla-logging-handler Commit: 2286b0ddcd63e1175bd1119fc0a4d69665d0a643 Parents: d868713 Author: mxmrlv <[email protected]> Authored: Mon Feb 13 13:35:25 2017 +0200 Committer: mxmrlv <[email protected]> Committed: Mon Feb 13 13:39:49 2017 +0200 ---------------------------------------------------------------------- aria/orchestrator/context/common.py | 19 +++++- aria/orchestrator/workflows/core/task.py | 18 +++--- aria/storage/core.py | 16 +++-- tests/orchestrator/context/test_operation.py | 72 ++++++++++++++++++++++- 4 files changed, 108 insertions(+), 17 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/blob/2286b0dd/aria/orchestrator/context/common.py ---------------------------------------------------------------------- diff --git a/aria/orchestrator/context/common.py b/aria/orchestrator/context/common.py index 6ab27ef..87f88b1 100644 --- a/aria/orchestrator/context/common.py +++ b/aria/orchestrator/context/common.py @@ -18,12 +18,13 @@ A common context for both workflow and operation from uuid import uuid4 import jinja2 +import logging from aria import logger from aria.storage import exceptions -class BaseContext(logger.LoggerMixin): +class BaseContext(object): """ Base context object for workflow and operation """ @@ -34,6 +35,7 @@ class BaseContext(logger.LoggerMixin): deployment_id, model_storage, resource_storage, + ctx_logger=None, workdir=None, **kwargs): super(BaseContext, self).__init__(**kwargs) @@ -42,6 +44,17 @@ class BaseContext(logger.LoggerMixin): self._model = model_storage self._resource = resource_storage self._deployment_id = deployment_id + if ctx_logger is None: + sqla_logging_handler = logger.create_sqla_log_handler(**model_storage.all_api_kwargs) + ctx_logger = logging.getLogger('aria_ctx') + + # A handler should be registered only once. + if len(ctx_logger.handlers) == 0: + ctx_logger.addHandler(sqla_logging_handler) + + ctx_logger.setLevel(logging.DEBUG) + self._logger = ctx_logger + self._workdir = workdir def __repr__(self): @@ -51,6 +64,10 @@ class BaseContext(logger.LoggerMixin): .format(name=self.__class__.__name__, self=self)) @property + def logger(self): + return self._logger + + @property def model(self): """ Access to the model storage http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/blob/2286b0dd/aria/orchestrator/workflows/core/task.py ---------------------------------------------------------------------- diff --git a/aria/orchestrator/workflows/core/task.py b/aria/orchestrator/workflows/core/task.py index f65fc0d..4d3a7f0 100644 --- a/aria/orchestrator/workflows/core/task.py +++ b/aria/orchestrator/workflows/core/task.py @@ -23,6 +23,8 @@ from functools import ( wraps, ) +import logging + from aria import logger from aria.storage import model from aria.orchestrator.context import operation as operation_context @@ -141,13 +143,15 @@ class OperationTask(BaseTask): ) self._workflow_context.model.task.put(operation_task) - self._ctx = context_class(name=api_task.name, - model_storage=self._workflow_context.model, - resource_storage=self._workflow_context.resource, - deployment_id=self._workflow_context._deployment_id, - task_id=operation_task.id, - actor_id=api_task.actor.id, - workdir=self._workflow_context._workdir) + self._ctx = context_class( + name=api_task.name, + model_storage=self._workflow_context.model, + resource_storage=self._workflow_context.resource, + deployment_id=self._workflow_context._deployment_id, + task_id=operation_task.id, + actor_id=api_task.actor.id, + workdir=self._workflow_context._workdir) + self._task_id = operation_task.id self._update_fields = None http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/blob/2286b0dd/aria/storage/core.py ---------------------------------------------------------------------- diff --git a/aria/storage/core.py b/aria/storage/core.py index 3878dca..705c861 100644 --- a/aria/storage/core.py +++ b/aria/storage/core.py @@ -87,6 +87,12 @@ class Storage(LoggerMixin): self.logger.debug('{name} object is ready: {0!r}'.format( self, name=self.__class__.__name__)) + @property + def all_api_kwargs(self): + kwargs = self._api_kwargs.copy() + kwargs.update(self._additional_api_kwargs) + return kwargs + def __repr__(self): return '{name}(api={self.api})'.format(name=self.__class__.__name__, self=self) @@ -124,9 +130,7 @@ class ResourceStorage(Storage): :param name: :return: """ - kwargs = self._api_kwargs.copy() - kwargs.update(self._additional_api_kwargs) - self.registered[name] = self.api(name=name, **kwargs) + self.registered[name] = self.api(name=name, **self.all_api_kwargs) self.registered[name].create() self.logger.debug('setup {name} in storage {self!r}'.format(name=name, self=self)) @@ -151,9 +155,9 @@ class ModelStorage(Storage): self.logger.debug('{name} in already storage {self!r}'.format(name=model_name, self=self)) return - kwargs = self._api_kwargs.copy() - kwargs.update(self._additional_api_kwargs) - self.registered[model_name] = self.api(name=model_name, model_cls=model_cls, **kwargs) + self.registered[model_name] = self.api(name=model_name, + model_cls=model_cls, + **self.all_api_kwargs) self.registered[model_name].create() self.logger.debug('setup {name} in storage {self!r}'.format(name=model_name, self=self)) http://git-wip-us.apache.org/repos/asf/incubator-ariatosca/blob/2286b0dd/tests/orchestrator/context/test_operation.py ---------------------------------------------------------------------- diff --git a/tests/orchestrator/context/test_operation.py b/tests/orchestrator/context/test_operation.py index e8c7cca..bab3fb9 100644 --- a/tests/orchestrator/context/test_operation.py +++ b/tests/orchestrator/context/test_operation.py @@ -15,6 +15,7 @@ import os +import logging import pytest from aria import ( @@ -60,7 +61,7 @@ def test_node_operation_task_execution(ctx, executor): node = ctx.model.node.get_by_name(mock.models.DEPENDENCY_NODE_NAME) node.operations[operation_name] = { - 'operation': op_path(my_operation, module_path=__name__) + 'operation': op_path(basic_operation, module_path=__name__) } ctx.model.node.update(node) @@ -99,7 +100,7 @@ def test_relationship_operation_task_execution(ctx, executor): operation_name = 'aria.interfaces.relationship_lifecycle.postconfigure' relationship = ctx.model.relationship.list()[0] relationship.source_operations[operation_name] = { - 'operation': op_path(my_operation, module_path=__name__) + 'operation': op_path(basic_operation, module_path=__name__) } ctx.model.relationship.update(relationship) relationship_instance = ctx.model.relationship_instance.list()[0] @@ -203,8 +204,73 @@ def test_plugin_workdir(ctx, executor, tmpdir): assert expected_file.read() == content +def test_operation_logging(ctx, executor): + operation_name = 'aria.interfaces.lifecycle.create' + + node = ctx.model.node.get_by_name(mock.models.DEPENDENCY_NODE_NAME) + node.operations[operation_name] = { + 'operation': op_path(logged_operation, module_path=__name__) + + } + ctx.model.node.update(node) + node_instance = ctx.model.node_instance.get_by_name(mock.models.DEPENDENCY_NODE_INSTANCE_NAME) + + wf_start = 'wf_start' + wf_end = 'wf_end' + + inputs = { + 'op_start': 'op_start', + 'op_end': 'op_end', + } + + @workflow + def basic_workflow(graph, ctx, **_): + ctx.logger.info(wf_start) + graph.add_tasks( + api.task.OperationTask.node_instance( + name=operation_name, + instance=node_instance, + inputs=inputs + ) + ) + ctx.logger.debug(wf_end) + + execute(workflow_func=basic_workflow, workflow_context=ctx, executor=executor) + + op_start_log = ctx.model.log.list(filters=dict(msg=inputs['op_start'])) + assert len(op_start_log) == 1 + op_start_log = op_start_log[0] + assert op_start_log.level.lower() == 'info' + + op_end_log = ctx.model.log.list(filters=dict(msg=inputs['op_end'])) + assert len(op_end_log) == 1 + op_end_log = op_end_log[0] + assert op_end_log.level.lower() == 'debug' + + wf_start_log = ctx.model.log.list(filters=dict(msg=wf_start)) + assert len(wf_start_log) == 1 + wf_start_log = wf_start_log[0] + assert wf_start_log.level.lower() == 'info' + + wf_end_log = ctx.model.log.list(filters=dict(msg=wf_end)) + assert len(wf_end_log) == 1 + wf_end_log = wf_end_log[0] + assert wf_end_log.level.lower() == 'debug' + + assert (wf_start_log.created_at < + wf_end_log.created_at < + op_start_log.created_at < + op_end_log.created_at) + +@operation +def logged_operation(ctx, **_): + ctx.logger.info(ctx.task.inputs['op_start']) + x = 1 + 2 + ctx.logger.debug(ctx.task.inputs['op_end']) + + @operation -def my_operation(ctx, **_): +def basic_operation(ctx, **_): global_test_holder[ctx.name] = ctx
