Regression of #3820 - Jinja is not rendered in action default values

[nmaludy]

ISSUE TYPE

• Bug Report

STACKSTORM VERSION

# st2 --version
st2 2.7.2, on Python 2.7

OS / ENVIRONMENT / INSTALL METHOD

Install method = puppet-st2
OS = Red Hat Enterprise Linux Server release 7.5 (Maipo)

SUMMARY

array and object parameters are not being rendered in action metadata parameter defaults. integer parameters work fine.

STEPS TO REPRODUCE

1) create a new action metadata file

/opt/stackstorm/packs/default/actions/render_test.yaml

---
description: Run a local linux command
enabled: true
runner_type: mistral-v2
entry_point: workflows/render_test.yaml
name: render_test
pack: default
parameters:
  cmd:
    required: true
    type: string
  timeout:
    type: integer
    default: 60
  kv_array:
    type: array
    default: "{{ st2kv.system.kv_array | from_json_string }}"
  kv_object:
    type: object
    default: "{{ st2kv.system.kv_object | from_json_string }}"

2) create a new workflow

/opt/stackstorm/packs/default/actions/workflows/render_test.yaml

version: '2.0'

default.render_test:
  description: demo rendering failures
  type: direct
  input:
    - cmd
    - timeout
    - kv_array
    - kv_object

  tasks:
    task1:
      action: core.local
      input:
        cmd: "{{ _.cmd }}"

3) assign values in the datastore

$ st2 key set kv_array '["a", "b", "c"]'
$ st2 key set kv_object '{"a": "value", "b": "value2", "c": "value3"}'

4) register and run the action

$ st2 action create /opt/stackstorm/packs/default/actions/render_test.yaml
$ st2 run default.render_test cmd="ls"

EXPECTED RESULTS

Action to execute successfully with parameters:

cmd: ls
timeout: 60
kv_array:
  - a
  - b
  - c
kv_object:
  a: value
  b: value2
  c: value3

ACTUAL RESULTS

$ st2 run default.render_test cmd="ls"
ERROR: 400 Client Error: Bad Request
MESSAGE: '{{ st2kv.system.kv_array | from_json_string }}' is not of type 'array' for url: http://127.0.0.1:9101/executions

Error in /var/log/st2/st2api.log

2018-05-30 15:39:22,101 139814525031760 ERROR actionexecutions [-] Unable to execute action. Parameter validation failed.
Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2api/controllers/v1/actionexecutions.py", line 127, in _handle_schedule_execution
    pack=action_db.pack)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2api/controllers/v1/actionexecutions.py", line 186, in _schedule_execution
    liveaction_db, actionexecution_db = action_service.create_request(liveaction_db)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/services/action.py", line 89, in create_request
    allow_default_none=True)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/schema/__init__.py", line 294, in validate
    jsonschema.validate(instance=instance, schema=schema, cls=cls, *args, **kwargs)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/jsonschema/validators.py", line 541, in validate
    cls(schema, *args, **kwargs).validate(instance)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/jsonschema/validators.py", line 130, in validate
    raise error
ValidationError: u'{{ st2kv.system.kv_array | from_json_string }}' is not of type u'array'

Failed validating u'type' in schema['properties'][u'kv_array']:
    {u'default': u'{{ st2kv.system.kv_array | from_json_string }}',
     u'type': u'array'}

On instance[u'kv_array']:
    u'{{ st2kv.system.kv_array | from_json_string }}'
2018-05-30 15:39:22,103 139814525031760 ERROR router [-] Failed to call controller function "post" for operation "st2api.controllers.v1.actionexecutions:action_executions_controller.post": '{{ st2kv.system.kv_array | from_json_string }}' is not of type 'array'
Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/router.py", line 470, in __call__
    resp = func(**kw)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2api/controllers/v1/actionexecutions.py", line 572, in post
    show_secrets=show_secrets)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2api/controllers/v1/actionexecutions.py", line 133, in _handle_schedule_execution
    abort(http_client.BAD_REQUEST, re.sub("u'([^']*)'", r"'\1'", e.message))
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/router.py", line 55, in abort
    raise exc.status_map[status_code](message)
HTTPBadRequest: '{{ st2kv.system.kv_array | from_json_string }}' is not of type 'array'

[Kami]

Just to confirm - did this behavior ever work in the past? If so, which version?

[nmaludy]

I believe it worked in the 2.6.x series. Just noticed it was broken in 2.7.2 (might have been broken sooner)

[Kami]

That's interesting since I don't remember us touching any of that code recently. Only somewhat related change was #4052

In any case, it looks like we should start with a test case. Another question also is why we don't have one for functionality we apparently support :)

[Kami]

I just tried to replicate the problem with the code you provided in v2.7.2, v2.7.1, v2.6.0 and v2.5.1. I get the same error message with every version (aka that functionality doesn't appear work / be supported).

Also looking at the PRs, that functionality was supposedly added in https://github.com/StackStorm/st2/pull/3892. Looking at the tests there - we only have tests for int scenario so likely there are more edge cases which are not handled correctly.

I will look into it and start with a test case for non-int values :)

[nmaludy]

@Kami good to know, i obviously never fully tested on my end.

Did a little digging this morning and found where it is failing specifically: https://github.com/StackStorm/st2/blob/master/st2common/st2common/util/param.py#L189

This is throwing the following exception:

Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2api/controllers/v1/actionexecutions.py", line 127, in _handle_schedule_execution
    pack=action_db.pack)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2api/controllers/v1/actionexecutions.py", line 182, in _schedule_execution
    liveaction_db.context)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/param.py", line 306, in render_live_params
    context = _resolve_dependencies(G)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/param.py", line 217, in _resolve_dependencies
    context[name] = _render(node, context)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/param.py", line 196, in _render
    result = ENV.from_string(str(node['template'])).render(render_context)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/jinja2/environment.py", line 1008, in render
    return self.environment.handle_exception(exc_info, True)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/jinja2/environment.py", line 780, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "<template>", line 1, in top-level template code
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/jinja/filters/data.py", line 29, in from_json_string
    return json.loads(value)
  File "/usr/lib64/python2.7/json/__init__.py", line 338, in loads
    return _default_decoder.decode(s)
  File "/usr/lib64/python2.7/json/decoder.py", line 366, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
TypeError: expected string or buffer

I turned on debug mode and here is the log for that node:

2018-05-31 07:20:58,097 139913045820592 INFO param [-] Rendering node: {'template': u'{{ st2kv.system.kv_array | from_json_string }}'} with context: {u'timeout': 60, 'st2kv': {'system': <st2common.services.keyvalues.KeyValueLookup object at 0x7f400b752a50>}}

It does not seem to be going into the if isinstance(node['template'], list) or isinstance(node['template'], dict): branch of a "complex type". Not sure if it should be going in there or not.

[Kami]

@nmaludy Alright, after some more digging in it turns out it's not an actual issue in the code, but it's related to calling filter on the value which has already been de-serialized (aka filter is being called twice - once internally based on the action parameter definition and again inside the parameter Jinja string which is not needed).

You don't need to call from_json_string filter on the template value. This is done automatically based on the parameter type.

The following works fine for me:

---
description: Run a local linux command
enabled: true
runner_type: mistral-v2
entry_point: workflows/render_test.yaml
name: render_test
pack: default
parameters:
  cmd:
    required: true
    type: string
  timeout:
    type: integer
    default: 60
  kv_array:
    type: array
    default: "{{ st2kv.system.kv_array }}"
  kv_object:
    type: object
    default: "{{ st2kv.system.kv_object }}"

I will close that as not an issue.

Having said that, I do agree that the current exception is very unfriendly. At the very least, exception should include more data which would give user some clue what is going in (I will look into that change).

[nmaludy]

Awesome! I really swore i tested it...

I'll make a PR for st2docs and try to make another PR to add tests for objects and arrays