Closed nmaludy closed 4 years ago
Doing some digging...
First i decided to output the execution results of the mistral workflow to see if the variable we were trying to publish was available in the right context, so i modified https://github.com/StackStorm/st2/blob/master/contrib/runners/action_chain_runner/action_chain_runner/action_chain_runner.py#L653-L654 to output the variable `execution_results.
This yielded the following on the CLI:
[root@stackstorm ~]# st2 run examples.testac
.
id: 5ae9f7b4a814c0066130b653
action.ref: examples.testac
parameters: None
status: failed
error: Failed rendering value for publish parameter "my_data" in task "chain_echo" (template string={{ chain_echo.data }}): 'dict object' has no attribute 'data' results={u'traceback': u' File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2actions/container/base.py", line 119, in _do_run
(status, result, context) = runner.run(action_params)
File "/opt/stackstorm/st2/lib/python2.7/site-packages/retrying.py", line 49, in wrapped_f
return Retrying(*dargs, **dkw).call(f, *args, **kw)
File "/opt/stackstorm/st2/lib/python2.7/site-packages/retrying.py", line 206, in call
return attempt.get(self._wrap_exception)
File "/opt/stackstorm/st2/lib/python2.7/site-packages/retrying.py", line 247, in get
six.reraise(self.value[0], self.value[1], self.value[2])
File "/opt/stackstorm/st2/lib/python2.7/site-packages/retrying.py", line 200, in call
attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
File "/opt/stackstorm/runners/mistral_v2/mistral_v2/mistral_v2.py", line 247, in run
result = self.start_workflow(action_parameters=action_parameters)
File "/opt/stackstorm/runners/mistral_v2/mistral_v2/mistral_v2.py", line 292, in start_workflow
**options)
File "/opt/stackstorm/st2/lib/python2.7/site-packages/mistralclient/api/v2/executions.py", line 65, in create
return self._create('/executions', data)
File "/opt/stackstorm/st2/lib/python2.7/site-packages/mistralclient/api/base.py", line 100, in _create
self._raise_api_exception(resp)
File "/opt/stackstorm/st2/lib/python2.7/site-packages/mistralclient/api/base.py", line 160, in _raise_api_exception
error_message=error_data)
', u'error': u"Can not evaluate Jinja expression [expression= chain_echo.data , error='chain_echo' is undefined, data={'__env': {u'st2_liveaction_id': u'5ae9f7b4a814c0189a1d4c6a', u'st2_execution_id': u'5ae9f7b4a814c0189a1d4c6b', u'__actions': {u'st2.action': {u'st2_context': {u'endpoint': u'http://127.0.0.1:9101/v1/actionexecutions', u'api_url': u'http://127.0.0.1:9101/v1', u'parent': {u'parent': {u'user': u'st2admin', u'execution_id': u'5ae9f7b4a814c0066130b653', u'pack': u'examples'}, u'user': u'st2admin', u'chain': {u'name': u'chain_echo', u'parameters': None, u'publish': {u'my_data': u'{{ chain_echo.data }}'}, u'params': None, u'notify': None, u'on_failure': None, u'ref': u'examples.testwf', u'on_success': None}, u'execution_id': u'5ae9f7b4a814c0189a1d4c6b', u'pack': u'examples'}, u'auth_token': u'xxx', u'skip_notify_tasks': [], u'notify': {}}}}, u'st2_action_api_url': u'http://127.0.0.1:9101/v1'}}]"}
traceback: File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2actions/container/base.py", line 119, in _do_run
(status, result, context) = runner.run(action_params)
File "/opt/stackstorm/runners/action_chain_runner/action_chain_runner/action_chain_runner.py", line 295, in run
return self._run_chain(action_parameters)
File "/opt/stackstorm/runners/action_chain_runner/action_chain_runner/action_chain_runner.py", line 531, in _run_chain
chain_vars=self.chain_holder.vars)
File "/opt/stackstorm/runners/action_chain_runner/action_chain_runner/action_chain_runner.py", line 656, in _render_publish_vars
raise action_exc.ParameterRenderingFailedException(msg)
start_timestamp: Wed, 02 May 2018 17:39:00 UTC
end_timestamp: Wed, 02 May 2018 17:39:01 UTC
+--------------------------+---------------------+------------+-----------------+-----------------+
| id | status | task | action | start_timestamp |
+--------------------------+---------------------+------------+-----------------+-----------------+
| 5ae9f7b4a814c0189a1d4c6b | failed (1s elapsed) | chain_echo | examples.testwf | Wed, 02 May |
| | | | | 2018 17:39:00 |
| | | | | UTC |
+--------------------------+---------------------+------------+-----------------+-----------------+
Now we can see that Mistral is getting an error... So, i modified the mistral runner here (https://github.com/StackStorm/st2/blob/master/contrib/runners/mistral_v2/mistral_v2/mistral_v2.py#L276) to output the values of inputs
and options
to see what the workflow was being passed and i got this in the logs:
2018-05-02 13:39:01,007 74242000 INFO mistral_v2 [-] Workflow inputs {}
2018-05-02 13:39:01,007 74242000 INFO mistral_v2 [-] Workflow options {'notify': [{'type': 'st2'}], 'env': {'st2_liveaction_id': '5ae9f7b4a814c0189a1d4c6a', 'st2_execution_id': '5ae9f7b4a814c0189a1d4c6b', '__actions': {'st2.action': {'st2_context': {'endpoint': 'http://127.0.0.1:9101/v1/actionexecutions', 'api_url': 'http://127.0.0.1:9101/v1', 'parent': {u'chain': {u'name': u'chain_echo', u'parameters': None, u'publish': {u'my_data': u'{{ chain_echo.data }}'}, u'params': None, u'notify': None, u'on_failure': None, u'ref': u'examples.testwf', u'on_success': None}, 'pack': u'examples', u'parent': {u'user': u'st2admin', u'execution_id': u'5ae9f7b4a814c0066130b653', u'pack': u'examples'}, 'execution_id': '5ae9f7b4a814c0189a1d4c6b', u'user': u'st2admin'}, 'auth_token': u'xxx', 'skip_notify_tasks': [], 'notify': {}}}}, 'st2_action_api_url': 'http://127.0.0.1:9101/v1'}}
Unpacking the options JSON yielded:
{
"notify": [
{
"type": "st2"
}
],
"env": {
"st2_liveaction_id": "5ae9f7b4a814c0189a1d4c6a",
"st2_execution_id": "5ae9f7b4a814c0189a1d4c6b",
"__actions": {
"st2.action": {
"st2_context": {
"endpoint": "http://127.0.0.1:9101/v1/actionexecutions",
"api_url": "http://127.0.0.1:9101/v1",
"parent": {
"chain": {
"name": "chain_echo",
"parameters": null,
"publish": {
"my_data": "{{ chain_echo.data }}"
},
"params": null,
"notify": null,
"on_failure": null,
"ref": "examples.testwf",
"on_success": null
},
"pack": "examples",
"parent": {
"user": "st2admin",
"execution_id": "5ae9f7b4a814c0066130b653",
"pack": "examples"
},
"execution_id": "5ae9f7b4a814c0189a1d4c6b",
"user": "st2admin"
},
"auth_token": "xxx",
"skip_notify_tasks": [],
"notify": {
}
}
}
},
"st2_action_api_url": "http://127.0.0.1:9101/v1"
}
}
Now you can see that the Jinja expression is passed into the Mistral workflow.
The following is present in the Mistral logs:
2018-05-02 13:39:01.033 1014 INFO workflow_trace [req-31a8194a-d6db-4f41-a322-a96e71bd4d8b - - - - -] Starting workflow [name=examples.testwf, input={}]
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server [req-31a8194a-d6db-4f41-a322-a96e71bd4d8b - - - - -] Exception during message handling: JinjaEvaluationException: Can not evaluate Jinja expression [expression= chain_echo.data , error='chain_echo' is undefined, data={'__env': {u'st2_liveaction_id': u'5ae9f7b4a814c0189a1d4c6a', u'st2_execution_id': u'5ae9f7b4a814c0189a1d4c6b', u'__actions': {u'st2.action': {u'st2_context': {u'endpoint': u'http://127.0.0.1:9101/v1/actionexecutions', u'api_url': u'http://127.0.0.1:9101/v1', u'parent': {u'parent': {u'user': u'st2admin', u'execution_id': u'5ae9f7b4a814c0066130b653', u'pack': u'examples'}, u'user': u'st2admin', u'chain': {u'name': u'chain_echo', u'parameters': None, u'publish': {u'my_data': u'{{ chain_echo.data }}'}, u'params': None, u'notify': None, u'on_failure': None, u'ref': u'examples.testwf', u'on_success': None}, u'execution_id': u'5ae9f7b4a814c0189a1d4c6b', u'pack': u'examples'}, u'auth_token': u''
, u'skip_notify_tasks': [], u'notify': {}}}}, u'st2_action_api_url': u'http://127.0.0.1:9101/v1'}}]
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 157, in _process_incoming
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 213, in dispatch
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _do_dispatch
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/engine/engine_server.py", line 111, in start_workflow
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server **params
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/db/utils.py", line 81, in decorate
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return _with_auth_context(auth_ctx, func, *args, **kw)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/tenacity/__init__.py", line 231, in wrapped_f
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return self.call(f, *args, **kw)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/tenacity/__init__.py", line 313, in call
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server start_time=start_time)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/tenacity/__init__.py", line 269, in iter
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return fut.result()
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/concurrent/futures/_base.py", line 455, in result
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return self.__get_result()
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/tenacity/__init__.py", line 316, in call
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server result = fn(*args, **kwargs)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/db/utils.py", line 50, in _with_auth_context
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return func(*args, **kw)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/engine/action_queue.py", line 94, in decorate
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server res = func(*args, **kw)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/engine/default_engine.py", line 61, in start_workflow
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server params
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/engine/workflow_handler.py", line 54, in start_workflow
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server params=params
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/osprofiler/profiler.py", line 158, in wrapper
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/engine/workflows.py", line 117, in start
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server params
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/engine/workflows.py", line 314, in _create_execution
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data_flow.add_environment_to_context(self.wf_ex)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/workflow/data_flow.py", line 305, in add_environment_to_context
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server {'__env': env}
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 89, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate_recursively(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 89, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate_recursively(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 89, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate_recursively(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 89, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate_recursively(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 89, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate_recursively(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 89, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate_recursively(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 100, in evaluate_recursively
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server data[key] = _evaluate_item(data[key], context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 79, in _evaluate_item
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluate(item, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/__init__.py", line 71, in evaluate
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server return evaluator.evaluate(expression, context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/jinja_expression.py", line 147, in evaluate
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server result = JinjaEvaluator.evaluate(patterns[0][1], data_context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server File "/opt/stackstorm/mistral/lib/python2.7/site-packages/mistral/expressions/jinja_expression.py", line 101, in evaluate
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server ", data=%s]" % (expression, str(e), data_context)
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server JinjaEvaluationException: Can not evaluate Jinja expression [expression= chain_echo.data , error='chain_echo' is undefined, data={'__env': {u'st2_liveaction_id': u'5ae9f7b4a814c0189a1d4c6a', u'st2_execution_id': u'5ae9f7b4a814c0189a1d4c6b', u'__actions': {u'st2.action': {u'st2_context': {u'endpoint': u'http://127.0.0.1:9101/v1/actionexecutions', u'api_url': u'http://127.0.0.1:9101/v1', u'parent': {u'parent': {u'user': u'st2admin', u'execution_id': u'5ae9f7b4a814c0066130b653', u'pack': u'examples'}, u'user': u'st2admin', u'chain': {u'name': u'chain_echo', u'parameters': None, u'publish': {u'my_data': u'{{ chain_echo.data }}'}, u'params': None, u'notify': None, u'on_failure': None, u'ref': u'examples.testwf', u'on_success': None}, u'execution_id': u'5ae9f7b4a814c0189a1d4c6b', u'pack': u'examples'}, u'auth_token': u'xxx', u'skip_notify_tasks': [], u'notify': {}}}}, u'st2_action_api_url': u'http://127.0.0.1:9101/v1'}}]
2018-05-02 13:39:01.040 1014 ERROR oslo_messaging.rpc.server
It appears that Mistral is trying to render the Jinja that is passed in the st2_context
and failing (rightly so)
Looks like there is a bug here with publish being evaluated before it should be. Thanks for reporting this. In the meantime, the work around is to use chain_echo.data
directly instead of publishing in the same task or use another task to publish.
High Level
Initially reported on Slack by @hreeder .
When trying to
publish
a variable in an ActionChain for a Mistral action, where thepublish
statement references the current action context, the publish fails.Steps to reproduce
Mistral Action Metadata
Mistral Workflow
ActionChain Action Metadata
ActionChain
Error
Workaround
If you split up the
publish
into the next task, then it works.