StackStorm / st2

StackStorm (aka "IFTTT for Ops") is event-driven automation for auto-remediation, incident responses, troubleshooting, deployments, and more for DevOps and SREs. Includes rules engine, workflow, 160 integration packs with 6000+ actions (see https://exchange.stackstorm.org) and ChatOps. Installer at https://docs.stackstorm.com/install/index.html
https://stackstorm.com/
Apache License 2.0
6.07k stars 749 forks source link

Mintral+Jinja ContextView object errors not reported #3456

Closed lampwins closed 7 years ago

lampwins commented 7 years ago

st2: 2.2.1 mistral: 2.2.1 python: 2.7.12

When using jinja to access a published var that does not exist, UndefinedError: 'mistral.workflow.data_flow.ContextView object' has no attribute '<var_name>' is not reported back to ST2 and the mistral action gets stuck in an RUNNING state. Switching the statement to YAQL reports an error and the task fails within ST2. Below is the error output discovered in /var/log/mistral/mistral-server.log


2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 155, in _process_incoming
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 222, in dispatch
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 192, in _do_dispatch
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/engine_server.py", line 154, in on_action_complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return self.engine.on_action_complete(action_ex_id, result, wf_action)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/db/utils.py", line 72, in decorate
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return _with_auth_context(auth_ctx, func, *args, **kw)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 417, in func
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return evt.wait()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/eventlet/event.py", line 121, in wait
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return hubs.get_hub().switch()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 294, in switch
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return self.greenlet.switch()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 137, in _run_loop
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     result = func(*self.args, **self.kw)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 388, in _func
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/db/utils.py", line 43, in _with_auth_context
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return func(*args, **kw)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/action_queue.py", line 70, in decorate
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     res = func(*args, **kw)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/default_engine.py", line 114, in on_action_complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     action_handler.on_action_complete(action_ex, result)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/action_handler.py", line 54, in on_action_complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     task_handler.schedule_on_action_complete(action_ex)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 360, in schedule_on_action_complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     _on_action_complete(action_ex)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 105, in _on_action_complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     task.on_action_complete(action_ex)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 264, in on_action_complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     self.complete(state, state_info)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 191, in complete
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     dispatcher.dispatch_workflow_commands(self.wf_ex, cmds)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/dispatcher.py", line 94, in dispatch_workflow_commands
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     task_handler.run_task(cmd)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 58, in run_task
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     task.run()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 269, in run
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     self._run_new()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 293, in _run_new
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     self._schedule_actions()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 351, in _schedule_actions
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     safe_rerun=self.task_spec.get_safe_rerun()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/actions.py", line 485, in schedule
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     wf_params
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/workflow_handler.py", line 41, in start_workflow
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     wf.start(wf_input, desc=desc, params=params)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/workflows.py", line 98, in start
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     dispatcher.dispatch_workflow_commands(self.wf_ex, cmds)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/dispatcher.py", line 94, in dispatch_workflow_commands
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     task_handler.run_task(cmd)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/task_handler.py", line 58, in run_task
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     task.run()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 269, in run
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     self._run_new()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 293, in _run_new
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     self._schedule_actions()
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 489, in _schedule_actions
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     input_dicts = self._get_input_dicts(with_items_values)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 576, in _get_input_dicts
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     result.append((i, self._get_action_input(ctx)))
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 153, in wrapper
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/engine/tasks.py", line 380, in _get_action_input
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     ctx_view
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 96, in evaluate_recursively
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     data[key] = _evaluate_item(data[key], context)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 85, in _evaluate_item
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return evaluate_recursively(item, context)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 96, in evaluate_recursively
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     data[key] = _evaluate_item(data[key], context)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 79, in _evaluate_item
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return evaluate(item, context)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 71, in evaluate
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return evaluator.evaluate(expression, context)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/mistral/expressions/jinja_expression.py", line 143, in evaluate
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     result = cls._env.from_string(expression).render(**ctx)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/jinja2/environment.py", line 1008, in render
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     return self.environment.handle_exception(exc_info, True)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "/opt/stackstorm/mistral/local/lib/python2.7/site-packages/jinja2/environment.py", line 780, in handle_exception
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server     reraise(exc_type, exc_value, tb)
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server   File "<template>", line 1, in top-level template code
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server UndefinedError: 'mistral.workflow.data_flow.ContextView object' has no attribute 'os_file'
2017-06-07 12:55:06.640 1479 ERROR oslo_messaging.rpc.server ```
m4dcoder commented 7 years ago

On st2 v2.3, I'm unable to reproduce this issue. I put together two separate workflows, posted below. In both cases, the Jinja evaluation error is reported back to st2 as failure.

Example 1 - Reference non-existent variable in Jinja

version: '2.0'

examples.mistral-jinja-test-error:
    description: A basic workflow for testing Jinja evaluation error. The workflow should error properly.
    type: direct
    tasks:
        task1:
            action: core.local
            input:
                cmd: "echo {{ _.IDontExist }}"
vagrant@arkham:~/st2$ st2 run examples.mistral-jinja-test-error -a
To get the results, execute:
 st2 execution get 596fa8431e2e240d31944201
vagrant@arkham:~/st2$ st2 execution get 596fa8431e2e240d31944201
id: 596fa8431e2e240d31944201
action.ref: examples.mistral-jinja-test-error
parameters: None
status: failed (1s elapsed)
start_timestamp: 2017-07-19T18:43:15.966727Z
end_timestamp: 2017-07-19T18:43:16.425031Z
result: 
  error: 'RemoteError: Remote error: UndefinedError ''mistral.workflow.data_flow.ContextView object'' has no attribute ''IDontExist''

Example 2 - Publish non-existent variable in Jinja

version: '2.0'

examples.mistral-jinja-test-publish-error:
    description: A basic workflow for testing Jinja evaluation error. The workflow should error properly.
    type: direct
    tasks:
        task1:
            action: core.local
            input:
                cmd: "echo 'all your base are belong to us'"
            publish:
                var1: "{{ _.IDontExist }}"

Please note status: failed below. You'll have to use st2 execution get <id> -dj to get the reason though.

vagrant@arkham:~/st2$ st2 execution get 596fa8581e2e240d31944204
id: 596fa8581e2e240d31944204
action.ref: examples.mistral-jinja-test-publish-error
parameters: None
status: failed (6s elapsed)
result_task: task1
result: 
  failed: false
  return_code: 0
  stderr: ''
  stdout: all your base are belong to us
  succeeded: true
start_timestamp: 2017-07-19T18:43:36.332119Z
end_timestamp: 2017-07-19T18:43:42.080302Z
+--------------------------+------------------------+-------+------------+-----------------+
| id                       | status                 | task  | action     | start_timestamp |
+--------------------------+------------------------+-------+------------+-----------------+
| 596fa8581e2e240d31944207 | succeeded (1s elapsed) | task1 | core.local | Wed, 19 Jul     |
|                          |                        |       |            | 2017 18:43:36   |
|                          |                        |       |            | UTC             |
+--------------------------+------------------------+-------+------------+-----------------+
m4dcoder commented 7 years ago

I'm going to close this issue as it's not reproducible. If you come across this problem again, please feel free to open the issue again with more information (WF definition, execution details) so we can reproduce it. Thanks.