Pack Config Jinja render failures do not provide good tracebacks

[nmaludy]

When working on #4121 i found another bug in the code.

Steps to reproduce

1. Install email pack (or any other pack) st2 pack install email
2. Create a config file /opt/stackstorm/packs/email.yaml with an invalid jinja expression in it

---
smtp_accounts:
  - name: me
    password: "password"
    port: 465
    secure: true
    server: "smtp.example.com"
    smtp_auth: true
    username: "user"
  - name: you
    password: "password"
    port: 465
    secure: true
    server: "smtp.example.com"
    smtp_auth: true
    username: "user"

imap_accounts:
  - name: me
    download_attachments: true
    folder: "INBOX"
    password: "super_S3c4e3t!"
    port: 993
    secure: true
    server: "imap.example.com"
    username: "me@example.com"
  - name: you
    download_attachments: true
    folder: "INBOX"
    password: "topsecret!"
    port: 993
    secure: true
    server: "imap.example.com"
    username: "you@example.com"
max_attachment_size: 1024
attachment_datastore_ttl: 1800
sensor_smtp_listen_ip: "{{ some invalid jinja that won't render properly }}"
sensor_smtp_listen_port: 25

3. Register the config st2ctl reload --register-configs
4. Run an action in that pack and you'll get the following error:

$ st2 run email.send_email email_from="nick.maludy@encore.tech" email_to=['nick.maludy@encore.tech'] subject="test subj" message="test message" account="me"
.
id: 5af3b8f4a814c021281db64c
status: failed
parameters: 
  account: me
  email_from: nick.maludy@encore.tech
  email_to:
  - '[nick.maludy@encore.tech]'
  message: test message
  subject: test subj
result: 
  error: __init__() takes at least 3 arguments (2 given)
  traceback: "  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2actions/worker.py", line 160, in _run_action
    result = self.container.dispatch(liveaction_db)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2actions/container/base.py", line 63, in dispatch
    runner = self._get_runner(runnertype_db, action_db, liveaction_db)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2actions/container/base.py", line 337, in _get_runner
    config = config_loader.get_config()
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/config_loader.py", line 83, in get_config
    config_db=config_db)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/config_loader.py", line 95, in _get_values_for_config
    config = self._assign_dynamic_config_values(schema=schema_values, config=config)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/config_loader.py", line 131, in _assign_dynamic_config_values
    config_schema_item=schema_item)
  File "/opt/stackstorm/st2/lib/python2.7/site-packages/st2common/util/config_loader.py", line 192, in _get_datastore_value_for_expression
    raise exc_class(msg)
"

Expected Behavior

The code https://github.com/StackStorm/st2/blob/master/st2common/st2common/util/config_loader.py#L192 should have re-thrown the underlying Jinja exception (jinja2.exceptions.TemplateSyntaxError). However, this exception signature takes a different number of parameters than what's being passed in: https://github.com/pallets/jinja/blob/master/jinja2/exceptions.py#L84

Since the code is only passing in a message and leaving out the lineno argument, a different exception is thrown for an invalid call. This defeats the purpose of catching/re-throwing in the first place.

Thoughts on a fix

I don't see many "good" ways to fix this that would be future proof while continuing to throw the underlying exception. My only thought would be to wrap up the exception details, add that to the message and throw a new exception type that we know and can control the parameters of.

[VineeshJain]

Here are my findings on this issue:

As of May 17, 2019, exception thrown is

.
id: 5cdca7190761295bf2dbfd87
status: failed
parameters:
  greeting: Vineesh Jain
result:
  error: 'Failed to render dynamic configuration value for key "test" with value "{{Invalid jinja expr}}" for pack "hello_st2" config: <class ''jinja2.exceptions.TemplateSyntaxError''> expected token ''end of print statement'', got ''jinja'' '
  traceback: "  File "/home/vagrant/st2/st2actions/st2actions/container/base.py", line 106, in _do_run
    runner.liveaction.context)
  File "/home/vagrant/st2/st2common/st2common/util/param.py", line 323, in render_final_params
    config = get_config(action_context.get('pack'), action_context.get('user'))
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 234, in get_config
    config = config_loader.get_config()
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 82, in get_config
    config_db=config_db)
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 94, in _get_values_for_config
    config = self._assign_dynamic_config_values(schema=schema_values, config=config)
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 150, in _assign_dynamic_config_values
    config_schema_item=schema_item)
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 212, in _get_datastore_value_for_expression
    raise RuntimeError(msg)
"
(virtualenv) vagrant@ubuntu-xenial:~/st2$

I believe this exception change is due to the commit 8096ba7

If needed, here is something we can do to improve further if needed.

        try:
            value = render_template_with_system_and_user_context(value=value,
                                                                 user=self.user)
        except jinja2.exceptions.TemplateError as e:
            exc_class = type(e)
            original_msg = str(e)
            msg = ('Failed to render dynamic configuration value for key "%s" with value '
                   '"%s" for pack "%s" config: %s %s ' % (key, value, self.pack_name, exc_class, original_msg))
            raise jinja2.exceptions.TemplateError(msg)
        except Exception as e:
            # Throw a more user-friendly exception on failed render
            exc_class = type(e)
            original_msg = six.text_type(e)
            msg = ('Failed to render dynamic configuration value for key "%s" with value '
                   '"%s" for pack "%s" config: %s %s ' % (key, value, self.pack_name,
                                                          exc_class, original_msg))
            raise exc_class(msg)

This way all Jinja template related errors will be caught specifically.

With the above code in place, we will get the following output:

(virtualenv) vagrant@ubuntu-xenial:~/st2$ st2 run hello_st2.greet greeting={{st2kv.system.vineesh}}
.
id: 5cdf16c80761291bd04ed729
status: failed
parameters:
  greeting: Vineesh Jain
result:
  error: 'Failed to render dynamic configuration value for key "test" with value "{{Invalid jinja expr}}" for pack "hello_st2" config: <class ''jinja2.exceptions.TemplateSyntaxError''> expected token ''end of print statement'', got ''jinja'' '
  traceback: "  File "/home/vagrant/st2/st2actions/st2actions/container/base.py", line 106, in _do_run
    runner.liveaction.context)
  File "/home/vagrant/st2/st2common/st2common/util/param.py", line 323, in render_final_params
    config = get_config(action_context.get('pack'), action_context.get('user'))
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 240, in get_config
    config = config_loader.get_config()
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 82, in get_config
    config_db=config_db)
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 94, in _get_values_for_config
    config = self._assign_dynamic_config_values(schema=schema_values, config=config)
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 150, in _assign_dynamic_config_values
    config_schema_item=schema_item)
  File "/home/vagrant/st2/st2common/st2common/util/config_loader.py", line 211, in _get_datastore_value_for_expression
    raise jinja2.exceptions.TemplateError(msg)

Let me know if this is acceptable and I can update the code and submit.

[m4dcoder]

@VineeshJain I can't tell the difference in the error message. Is there additional information from the error message in the jinja2.exceptions.TemplateError exception? The only difference here is that I can see in the traceback that it is raise by jinja2.exceptions.TemplateError and not RuntimeError.

[VineeshJain]

@m4dcoder Yes mainly that is the difference. Original issue mentioned that TemplateSyntaxError can only take 3 arguments. TemplateError is the base class for all Jinja errors which takes 2 arguments. Also, I feel it is better that we catch TemplateError for all jinja related errors and catch a generic Exception for all other types of exceptions. That way it is clearly identified that the issue is related to Jinja or due to any other issue. Also, the error message is defined by us, we can change it to anything we want, let me know if you think the message is not good enough. Keep in mind though, we should have a cover-all sought of message for all TemplateErrors and not specific to TemplateSyntaxError. We can catch the TemplateSyntaxError specifically as well and raise is as is without modifying it at all.

[m4dcoder]

IMO, no additional change is required since there is already a fix committed. The specific error type is already included in the error message. There's no new information in this proposal. Otherwise we will have to keep expanding the try-except block to add more specific error types.

[nmaludy]

Looks like i forgot to close the issue after i fixed it last year. Closing.