diff --git a/mistral/engine/engine_server.py b/mistral/engine/engine_server.py index ed868fc5..95c5053c 100644 --- a/mistral/engine/engine_server.py +++ b/mistral/engine/engine_server.py @@ -91,10 +91,9 @@ class EngineServer(service_base.MistralService): """ LOG.info( - "Received RPC request 'start_workflow'[rpc_ctx=%s," - " workflow_identifier=%s, workflow_input=%s, description=%s, " - "params=%s]" % - (rpc_ctx, workflow_identifier, utils.cut(workflow_input), + "Received RPC request 'start_workflow'[workflow_identifier=%s, " + "workflow_input=%s, description=%s, params=%s]" % + (workflow_identifier, utils.cut(workflow_input), description, params) ) @@ -117,10 +116,9 @@ class EngineServer(service_base.MistralService): :return: Action execution. """ LOG.info( - "Received RPC request 'start_action'[rpc_ctx=%s," - " name=%s, input=%s, description=%s, params=%s]" - % (rpc_ctx, action_name, utils.cut(action_input), - description, params) + "Received RPC request 'start_action'[name=%s, input=%s, " + "description=%s, params=%s]" + % (action_name, utils.cut(action_input), description, params) ) return self.engine.start_action( @@ -139,11 +137,9 @@ class EngineServer(service_base.MistralService): :param wf_action: True if given id points to a workflow execution. :return: Action execution. """ - LOG.info( - "Received RPC request 'on_action_complete'[rpc_ctx=%s," - " action_ex_id=%s, result=%s]" % - (rpc_ctx, action_ex_id, result.cut_repr()) + "Received RPC request 'on_action_complete'[action_ex_id=%s, " + "result=%s]" % (action_ex_id, result.cut_repr()) ) return self.engine.on_action_complete(action_ex_id, result, wf_action) @@ -155,10 +151,9 @@ class EngineServer(service_base.MistralService): :param execution_id: Workflow execution id. :return: Workflow execution. """ - LOG.info( - "Received RPC request 'pause_workflow'[rpc_ctx=%s," - " execution_id=%s]" % (rpc_ctx, execution_id) + "Received RPC request 'pause_workflow'[execution_id=%s]" % + execution_id ) return self.engine.pause_workflow(execution_id) @@ -172,10 +167,9 @@ class EngineServer(service_base.MistralService): :param env: Environment variables to update. :return: Workflow execution. """ - LOG.info( - "Received RPC request 'rerun_workflow'[rpc_ctx=%s, " - "task_ex_id=%s]" % (rpc_ctx, task_ex_id) + "Received RPC request 'rerun_workflow'[task_ex_id=%s]" % + task_ex_id ) return self.engine.rerun_workflow(task_ex_id, reset, env) @@ -188,10 +182,8 @@ class EngineServer(service_base.MistralService): :param env: Environment variables to update. :return: Workflow execution. """ - LOG.info( - "Received RPC request 'resume_workflow'[rpc_ctx=%s, " - "wf_ex_id=%s]" % (rpc_ctx, wf_ex_id) + "Received RPC request 'resume_workflow'[wf_ex_id=%s]" % wf_ex_id ) return self.engine.resume_workflow(wf_ex_id, env) @@ -211,11 +203,10 @@ class EngineServer(service_base.MistralService): :return: Workflow execution. """ - LOG.info( - "Received RPC request 'stop_workflow'[rpc_ctx=%s, execution_id=%s," + "Received RPC request 'stop_workflow'[execution_id=%s," " state=%s, message=%s]" % - (rpc_ctx, execution_id, state, message) + (execution_id, state, message) ) return self.engine.stop_workflow(execution_id, state, message) @@ -226,10 +217,9 @@ class EngineServer(service_base.MistralService): :param rpc_ctx: RPC request context. :return: Workflow execution. """ - LOG.info( - "Received RPC request 'rollback_workflow'[rpc_ctx=%s," - " execution_id=%s]" % (rpc_ctx, execution_id) + "Received RPC request 'rollback_workflow'[execution_id=%s]" % + execution_id ) return self.engine.rollback_workflow(execution_id) diff --git a/mistral/engine/executor_server.py b/mistral/engine/executor_server.py index 9b5b8891..4159bb54 100644 --- a/mistral/engine/executor_server.py +++ b/mistral/engine/executor_server.py @@ -73,9 +73,9 @@ class ExecutorServer(service_base.MistralService): """ LOG.info( - "Received RPC request 'run_action'[rpc_ctx=%s," - " action_ex_id=%s, action_class=%s, attributes=%s, params=%s]" - % (rpc_ctx, action_ex_id, action_class_str, attributes, + "Received RPC request 'run_action'[action_ex_id=%s, " + "action_class=%s, attributes=%s, params=%s]" + % (action_ex_id, action_class_str, attributes, utils.cut(params)) ) diff --git a/mistral/engine/task_handler.py b/mistral/engine/task_handler.py index f45b512f..d0291503 100644 --- a/mistral/engine/task_handler.py +++ b/mistral/engine/task_handler.py @@ -62,7 +62,7 @@ def run_task(wf_cmd): msg = ( "Failed to run task [error=%s, wf=%s, task=%s]:\n%s" % - (e, wf_ex, task_spec.get_name(), tb.format_exc()) + (e, wf_ex.name, task_spec.get_name(), tb.format_exc()) ) LOG.error(msg) @@ -159,7 +159,7 @@ def continue_task(task_ex): msg = ( "Failed to run task [error=%s, wf=%s, task=%s]:\n%s" % - (e, wf_ex, task_ex.name, tb.format_exc()) + (e, wf_ex.name, task_ex.name, tb.format_exc()) ) LOG.error(msg) @@ -185,7 +185,7 @@ def complete_task(task_ex, state, state_info): msg = ( "Failed to complete task [error=%s, wf=%s, task=%s]:\n%s" % - (e, wf_ex, task_ex.name, tb.format_exc()) + (e, wf_ex.name, task_ex.name, tb.format_exc()) ) LOG.error(msg) @@ -296,8 +296,8 @@ def _refresh_task_state(task_ex_id): else: # Must never get here. raise RuntimeError( - 'Unexpected logical task state [task_ex=%s, state=%s]' % - (task_ex, state) + 'Unexpected logical task state [task_ex_id=%s, task_name=%s, ' + 'state=%s]' % (task_ex_id, task_ex.name, state) ) diff --git a/mistral/engine/tasks.py b/mistral/engine/tasks.py index 7e6d2ed9..2864450f 100644 --- a/mistral/engine/tasks.py +++ b/mistral/engine/tasks.py @@ -280,8 +280,8 @@ class RegularTask(Task): self._create_task_execution() LOG.debug( - 'Starting task [workflow=%s, task_spec=%s, init_state=%s]' % - (self.wf_ex.name, self.task_spec, self.task_ex.state) + 'Starting task [workflow=%s, task=%s, init_state=%s]' % + (self.wf_ex.name, self.task_spec.get_name(), self.task_ex.state) ) self._before_task_start() diff --git a/mistral/engine/workflow_handler.py b/mistral/engine/workflow_handler.py index ec1d2cb8..2f3423e4 100644 --- a/mistral/engine/workflow_handler.py +++ b/mistral/engine/workflow_handler.py @@ -92,8 +92,8 @@ def _check_and_complete(wf_ex_id): incomplete_tasks_count = wf.check_and_complete() except exc.MistralException as e: msg = ( - "Failed to check and complete [wf_ex=%s]:" - " %s\n%s" % (wf_ex, e, tb.format_exc()) + "Failed to check and complete [wf_ex_id=%s, wf_name=%s]:" + " %s\n%s" % (wf_ex_id, wf_ex.name, e, tb.format_exc()) ) LOG.error(msg) @@ -154,7 +154,8 @@ def set_workflow_state(wf_ex, state, msg=None): pause_workflow(wf_ex, msg) else: raise exc.MistralError( - 'Invalid workflow state [wf_ex=%s, state=%s]' % (wf_ex, state) + 'Invalid workflow execution state [wf_ex_id=%s, wf_name=%s, ' + 'state=%s]' % (wf_ex.id, wf_ex.name, state) ) diff --git a/mistral/engine/workflows.py b/mistral/engine/workflows.py index ca137626..3ea5479c 100644 --- a/mistral/engine/workflows.py +++ b/mistral/engine/workflows.py @@ -219,8 +219,11 @@ class Workflow(object): final_context = wf_ctrl.evaluate_workflow_final_context() except Exception as e: LOG.warning( - 'Failed to get final context for %s: %s' % (self.wf_ex, e) + 'Failed to get final context for workflow execution. ' + '[wf_ex_id: %s, wf_name: %s, error: %s]' % + (self.wf_ex.id, self.wf_ex.name, str(e)) ) + return final_context def _create_execution(self, wf_def, input_dict, desc, params): diff --git a/mistral/services/scheduler.py b/mistral/services/scheduler.py index 17609a23..0226d6a0 100644 --- a/mistral/services/scheduler.py +++ b/mistral/services/scheduler.py @@ -133,7 +133,12 @@ class CallScheduler(periodic_task.PeriodicTasks): calls_to_make.append(result) for call in calls_to_make: - LOG.debug('Processing next delayed call: %s', call) + LOG.debug( + 'Processing next delayed call. ' + '[ID=%s, factory_method_path=%s, target_method_name=%s, ' + 'method_arguments=%s]', call.id, call.factory_method_path, + call.target_method_name, call.method_arguments + ) target_auth_context = copy.deepcopy(call.auth_context) diff --git a/mistral/workflow/data_flow.py b/mistral/workflow/data_flow.py index 420c0332..3436c463 100644 --- a/mistral/workflow/data_flow.py +++ b/mistral/workflow/data_flow.py @@ -267,8 +267,6 @@ def add_openstack_data_to_context(wf_ex): if CONF.pecan.auth_enable: exec_ctx = auth_ctx.ctx() - LOG.debug('Data flow security context: %s' % exec_ctx) - if exec_ctx: wf_ex.context.update({'openstack': exec_ctx.to_dict()})