Closed
Description
SUMMARY
When using orquesta workflows if a task fails but still publishes content the workflow is marked as succeeded. This happens if there is no when clause and when there is a when failed clause.
STACKSTORM VERSION
# st2 --version
st2 3.1.0, on Python 2.7.5
OS, environment, install method
# cat /etc/os-release
NAME="Red Hat Enterprise Linux Server"
VERSION="7.6 (Maipo)"
ID="rhel"
Install method is Puppet forge module
Steps to reproduce the problem
Using the examples.orquesta-basic workflow. We can need to modify the workflow to remove the when: <% succeeded() %> or modify it to be when: <% succeeded() or failed() %>
Workflow:
version: 1.0
description: A basic workflow that runs an arbitrary linux command.
input:
- cmd
- timeout
tasks:
task1:
action: core.local cmd=<% ctx(cmd) %> timeout=<% ctx(timeout) %>
next:
- when: <% succeeded() or failed() %>
publish:
- stdout: <% result().stdout %>
- stderr: <% result().stderr %>
output:
- stdout: <% ctx(stdout) %>
or:
version: 1.0
description: A basic workflow that runs an arbitrary linux command.
input:
- cmd
- timeout
tasks:
task1:
action: core.local cmd=<% ctx(cmd) %> timeout=<% ctx(timeout) %>
next:
- publish:
- stdout: <% result().stdout %>
- stderr: <% result().stderr %>
output:
- stdout: <% ctx(stdout) %>
Action file was unaltered:
---
name: orquesta-basic
pack: examples
description: Run a local linux command
runner_type: orquesta
entry_point: workflows/orquesta-basic.yaml
enabled: true
parameters:
cmd:
required: true
type: string
timeout:
type: integer
default: 60
can be forced to fail by running invalid command:
st2 run examples.orquesta-basic cmd="secho 'hi'"
Expected Results
I would expect the results of the workflow to be failed when the task fails unless manually overridden.
Actual Results
The workflow says succeeded even though the single task failed. Looking at the logs it looks like a second subtask is formed for the publish method that succeeds and send that to the workflow.
# st2 run examples.orquesta-basic cmd="secho 'hi'"
..
id: 5d289d9e49b3d2af833a29a9
action.ref: examples.orquesta-basic
parameters:
cmd: secho 'hi'
status: succeeded
start_timestamp: Fri, 12 Jul 2019 14:47:58 UTC
end_timestamp: Fri, 12 Jul 2019 14:48:02 UTC
result:
output:
stdout: ''
+--------------------------+---------------------+-------+------------+-------------------------------+
| id | status | task | action | start_timestamp |
+--------------------------+---------------------+-------+------------+-------------------------------+
| 5d289da049b3d2af5f26fa4f | failed (1s elapsed) | task1 | core.local | Fri, 12 Jul 2019 14:48:00 UTC |
+--------------------------+---------------------+-------+------------+-------------------------------+
Added debugging logs to:
https://github.com/StackStorm/orquesta/blob/master/orquesta/conducting.py#L624
and produced the following logs showing the second subtask.
2019-07-12 09:38:43,757 140001394854000 DEBUG conducting [-] Conductor Event Status: [failed]
2019-07-12 09:38:43,757 140001394854000 DEBUG conducting [-] Conductor staged task: None
2019-07-12 09:38:43,758 140001394854000 DEBUG conducting [-] Conductor task state entry: {u'status': u'running', u'route': 0, u'next': {}, u'ctxs': {u'in': [0]}, u'prev': {}, u'id': u'task1'}
2019-07-12 09:38:43,758 140001394854000 DEBUG conducting [-] Conductor task state entry: {u'status': u'running', u'route': 0, u'next': {}, u'ctxs': {u'in': [0]}, u'prev': {}, u'id': u'task1'}
2019-07-12 09:38:43,759 140001394854000 DEBUG conducting [-] Conductor task state idx: 0
2019-07-12 09:38:43,759 140001394854000 DEBUG conducting [-] Conductor task state entry: {u'status': u'running', u'route': 0, u'next': {}, u'ctxs': {u'in': [0]}, u'prev': {}, u'id': u'task1'}
2019-07-12 09:38:43,760 140001394854000 DEBUG conducting [-] Conductor task state idx: 0
2019-07-12 09:38:43,761 140001394854000 DEBUG conducting [-] Conductor staged task: None
2019-07-12 09:38:43,761 140001394854000 DEBUG conducting [-] Conductor old task status: running
2019-07-12 09:38:43,762 140001394854000 DEBUG conducting [-] Conductor new task status: failed
2019-07-12 09:38:43,770 140001394854000 DEBUG conducting [-] Conductor Event Status: [succeeded]
2019-07-12 09:38:43,771 140001394854000 DEBUG conducting [-] Conductor staged task: {'ready': True, 'route': 0, 'ctxs': {'in': [0, 1]}, 'prev': {u'task1__t0': 0}, 'id': u'noop'}
2019-07-12 09:38:43,771 140001394854000 DEBUG conducting [-] Conductor task state entry: None
2019-07-12 09:38:43,772 140001394854000 DEBUG conducting [-] Conductor task state entry: {'ctxs': {'in': [0, 1]}, 'route': 0, 'prev': {u'task1__t0': 0}, 'id': u'noop', 'next': {}}
2019-07-12 09:38:43,772 140001394854000 DEBUG conducting [-] Conductor task state idx: 1
2019-07-12 09:38:43,773 140001394854000 DEBUG conducting [-] Conductor task state entry: {'ctxs': {'in': [0, 1]}, 'route': 0, 'prev': {u'task1__t0': 0}, 'id': u'noop', 'next': {}}
2019-07-12 09:38:43,774 140001394854000 DEBUG conducting [-] Conductor task state idx: 1
2019-07-12 09:38:43,774 140001394854000 DEBUG conducting [-] Conductor staged task: {'ready': True, 'route': 0, 'ctxs': {'in': [0, 1]}, 'prev': {u'task1__t0': 0}, 'id': u'noop'}
2019-07-12 09:38:43,775 140001394854000 DEBUG conducting [-] Conductor old task status: null
2019-07-12 09:38:43,775 140001394854000 DEBUG conducting [-] Conductor new task status: succeeded
2019-07-12 09:38:43,793 140001394854000 DEBUG workflows [-] [5d288d6149b3d2af833a2991] Conductor: {'state': {'status': 'succeeded', 'tasks': {u'task1__r0': 0, u'noop__r0': 1}, 'sequence': [{u'status': 'failed', 'term': True, u'route': 0, u'next': {u'noop__t0': True}, u'ctxs': {u'in': [0], 'out': {u'noop__t0': 1}}, u'prev': {}, u'id': u'task1'}, {'status': 'succeeded', 'term': True, 'route': 0, 'next': {}, 'ctxs': {'in': [0, 1]}, 'prev': {u'task1__t0': 0}, 'id': u'noop'}], 'contexts': [{u'parent': {u'user': u'test', u'pack': u'examples'}, u'cmd': u"secho 'hi'", u'st2': {u'workflow_execution_id': u'5d288d6249b3d2ae94b89c73', u'pack': u'examples', u'action_execution_id': u'5d288d6149b3d2af833a2991', u'api_url': u'http://127.0.0.1:9101/v1', u'user': u'test'}, u'timeout': 60}, {u'stdout': {u'failed': True, u'stderr': u'bash: secho: command not found', u'return_code': 127, u'succeeded': False, u'stdout': u''}}], 'staged': [], 'routes': [[]]}, 'errors': [{'message': 'Execution failed. See result for details.', 'type': 'error', 'result': {u'succeeded': False, u'failed': True, u'return_code': 127, u'stderr': u'bash: secho: command not found', u'stdout': u''}, 'task_id': u'task1'}], 'log': [], 'context': {u'parent': {u'user': u'test', u'pack': u'examples'}, u'st2': {u'workflow_execution_id': u'5d288d6249b3d2ae94b89c73', u'user': u'test', u'action_execution_id': u'5d288d6149b3d2af833a2991', u'api_url': u'http://127.0.0.1:9101/v1', u'pack': u'examples'}}, 'input': {u'cmd': u"secho 'hi'", u'timeout': 60}, 'graph': {'directed': True, 'graph': [], 'nodes': [{'id': u'task1'}, {'id': u'noop'}], 'adjacency': [[{u'ref': 0, u'id': u'noop', u'key': 0, u'criteria': []}], []], 'multigraph': True}, 'spec': {'catalog': 'native', 'version': '1.0', 'spec': {u'input': [u'cmd', u'timeout'], u'tasks': {u'task1': {u'action': u'core.local cmd=<% ctx(cmd) %> timeout=<% ctx(timeout) %>', u'next': [{u'publish': [{u'stdout': u'<% result() %>'}]}]}}, u'description': u'A basic workflow that runs an arbitrary linux command.', u'version': 1.0, u'output': [{u'stdout': u'<% ctx(stdout) %>'}]}}, 'output': {u'stdout': {u'failed': True, u'stderr': u'bash: secho: command not found', u'return_code': 127, u'succeeded': False, u'stdout': u''}}}
2019-07-12 09:38:43,795 140001394854000 INFO workflows [-] [5d288d6149b3d2af833a2991] Updating workflow execution from status "running" to "succeeded".
2019-07-12 09:38:43,857 140001394854000 DEBUG workflows [-] [5d288d6149b3d2af833a2991] Updating workflow liveaction from status "running" to "succeeded".