Troubleshooting rules failing to start executions

I have a rule that has stopped working. The rule tries to start an execution but fails.

The following traceback is in my rules engine log:

Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2reactor/rules/enforcer.py", line 94, in enforce
    execution_db = self._do_enforce()
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2reactor/rules/enforcer.py", line 143, in _do_enforce
    additional_contexts=additional_contexts)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2reactor/rules/enforcer.py", line 196, in _invoke_action
    additional_contexts=additional_contexts)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2reactor/rules/enforcer.py", line 80, in get_resolved_parameters
    additional_contexts=additional_contexts)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/param.py", line 298, in render_live_params
    live_params = _cast_params_from(params, context, [action_parameters, runner_parameters])
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/param.py", line 232, in _cast_params_from
    result[name] = _cast(context[name], param_schema)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/param.py", line 75, in _cast
    return cast(v)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/casts.py", line 39, in _cast_object
    return ast.literal_eval(x)
  File "/usr/lib64/python2.7/ast.py", line 49, in literal_eval
    node_or_string = parse(node_or_string, mode='eval')
  File "/usr/lib64/python2.7/ast.py", line 37, in parse
    return compile(source, filename, mode, PyCF_ONLY_AST)
  File "<unknown>", line 1
    <built-in method keys of BaseDict object at 0x57be940>
    ^

relevant output of rule-enforcement:

+--------------------------+--------------------------------------+--------------------------+--------------------------+-----------------------------+
| id                       | rule.ref                             | trigger_instance_id      | execution_id             | enforced_at                 |
+--------------------------+--------------------------------------+--------------------------+--------------------------+-----------------------------+
| 5b07c28402ebd54ce6865159 | pharoslaas.on_end_deployment_trigger | 5b07c28402ebd54ce6865156 |                          | 2018-05-25T08:00:04.151003Z |
| 5b078a4602ebd54ce6863fb0 | pharoslaas.on_end_deployment_trigger | 5b078a4602ebd54ce6863fae |                          | 2018-05-25T04:00:06.067578Z |
| 5b0735e902ebd54ce6862587 | pharoslaas.on_end_deployment_trigger | 5b0735e902ebd54ce6862584 |                          | 2018-05-24T22:00:09.247676Z |
| 5b06008002ebd54ce685c5b6 | pharoslaas.on_end_deployment_trigger | 5b06008002ebd54ce685c5b3 |                          | 2018-05-24T00:00:00.779763Z |
| 5afeea8502ebd54ce683403f | pharoslaas.on_end_deployment_trigger | 5afeea8502ebd54ce683403c |                          | 2018-05-18T15:00:21.166756Z |
| 5afea43802ebd54ce68331a0 | pharoslaas.on_end_deployment_trigger | 5afea43702ebd54ce683319d |                          | 2018-05-18T10:00:24.003795Z |
| 5afbec2802ebd54ce682a537 | pharoslaas.on_end_deployment_trigger | 5afbec2802ebd54ce682a533 | 5afbec2802ebd54ce682a536 | 2018-05-16T08:30:32.414416Z |
| 5afbc1f902ebd54ce682a01a | pharoslaas.on_end_deployment_trigger | 5afbc1f902ebd54ce682a015 | 5afbc1f902ebd54ce682a019 | 2018-05-16T05:30:33.624886Z |

And trigger-list

+--------------------------+-----------------------------------+-------------------------------+-----------+
| id                       | trigger                           | occurrence_time               | status    |
+--------------------------+-----------------------------------+-------------------------------+-----------+
| 5afbec2802ebd54ce682a533 | pharoslaas.end_deployment_trigger | Wed, 16 May 2018 08:30:32 UTC | processed |
| 5afea43702ebd54ce683319d | pharoslaas.end_deployment_trigger | Fri, 18 May 2018 10:00:23 UTC | processed |
| 5afeea8502ebd54ce683403c | pharoslaas.end_deployment_trigger | Fri, 18 May 2018 15:00:21 UTC | processed |
| 5b06008002ebd54ce685c5b3 | pharoslaas.end_deployment_trigger | Thu, 24 May 2018 00:00:00 UTC | processed |
| 5b0735e902ebd54ce6862584 | pharoslaas.end_deployment_trigger | Thu, 24 May 2018 22:00:09 UTC | processed |
| 5b078a4602ebd54ce6863fae | pharoslaas.end_deployment_trigger | Fri, 25 May 2018 04:00:06 UTC | processed |
| 5b07c28402ebd54ce6865156 | pharoslaas.end_deployment_trigger | Fri, 25 May 2018 08:00:04 UTC | processed |
+--------------------------+-----------------------------------+-------------------------------+-----------+

And the rule itself:

---
name: on_end_deployment_trigger
pack: pharoslaas
description: dummy rule to link end deployment trigger to clean action
enabled: true
trigger:
    type: pharoslaas.end_deployment_trigger
action:
    ref: pharoslaas.clean-workflow
    parameters:
        host: "{{ trigger.host }}"
        key: "{{trigger.key}}"
        user: "{{trigger.user}}"
        keys: "{{trigger.keys}}"

I have a rule that has stopped working

So it did work in the past, but no longer works? What has changed since? Different ST2 version, or change in the trigger content?

My guess is that something’s failing to render due to some problem with the trigger body - e.g. maybe it doesn’t contain the expected keys value.

What does st2 trigger-instance get <ID> look like, for one of your trigger instances?

Yes. It’s hard to see in the output, but the rule enforcement shows that the trigger stopped successfully causing executions around a week ago. This did correspond with a change in structure of the trigger.

+-----------------+-----------------------------------+
| Property        | Value                             |
+-----------------+-----------------------------------+
| id              | 5afeea8502ebd54ce683403c          |
| trigger         | pharoslaas.end_deployment_trigger |
| occurrence_time | 2018-05-18T15:00:21.132000Z       |
| payload         | {                                 |
|                 |     "keys": [],                   |
|                 |     "host": "hpe16",              |
|                 |     "user": 22,                   |
|                 |     "key": "vpn_yCxgJZp0",        |
|                 |     "booking": 145                |
|                 | }                                 |
| status          | processed                         |
+-----------------+-----------------------------------+

is the trigger instance. Is having an empty array invalid?

It’s possible that the empty array is causing a problem. I haven’t tried using an empty array. As a test, what happens if you remove the keys: “{{trigger.keys}}” line from the rule?

This did correspond with a change in structure of the trigger.

What was the structure change?

The other thing that’s going on here is your use of ‘keys’ - this is almost certainly getting confused with the Python dict built-in keys. I would recommend using a different name.

It seems that changing the name in the trigger payload to extra_keys fixes this problem