Better trace for nested jinja errors

salt/utils/templates.py

@@ -104,20 +104,94 @@ def wrap_tmpl_func(render_str):
     return render_tmpl
 
 
-def _get_jinja_error_line(tb_data):
+def _get_jinja_error_slug(tb_data):
     '''
     Return the line number where the template error was found
     '''
     try:
         return [
-            x[1] for x in tb_data if x[2] in ('top-level template code',
+            x
+            for x in tb_data if x[2] in ('top-level template code',
                                          'template')
         ][-1]
     except IndexError:
         pass
+
+
+def _get_jinja_error_message(tb_data):
+    '''
+    Return an understandable message from jinja error output
+    '''
+    try:
+        line = _get_jinja_error_slug(tb_data)
+        return u'{0}({1}):\n{3}'.format(*line)
+    except IndexError:
+        pass
     return None
 
 
+def _get_jinja_error_line(tb_data):
+    '''
+    Return the line number where the template error was found
+    '''
+    try:
+        return _get_jinja_error_slug(tb_data)[1]
+    except IndexError:
+        pass
+    return None
+
+
+def _get_jinja_error(trace, context=None):
+    '''
+    Return the error line and error message output from
+    a stacktrace.
+    If we are in a macro, also output inside the message the
+    exact location of the error in the macro
+    '''
+    if not context:
+        context = {}
+    out = ''
+    error = _get_jinja_error_slug(trace)
+    line = _get_jinja_error_line(trace)
+    msg = _get_jinja_error_message(trace)
+    # if we failed on a nested macro, output a little more info
+    # to help debugging
+    # if sls is not found in context, add output only if we can
+    # resolve the filename
+    add_log = False
+    template_path = None
+    if not 'sls' in context:
+        if (
+            (error[0] != '<unknown>')
+            and os.path.exists(error[0])
+        ):
+            template_path = error[0]
+            add_log = True
+    else:
+        # the offender error is not from the called sls
+        filen = context['sls'].replace('.', '/')
+        if (
+            not error[0].endswith(filen)
+            and os.path.exists(error[0])
+        ):
+            add_log = True
+            template_path = error[0]
+    # if we add a log, format explicitly the exeception here
+    # by telling to output the macro context after the macro
+    # error log place at the beginning
+    if add_log:
+        if template_path:
+            out = '\n{}\n'.format(msg.splitlines()[0])
+            out += salt.utils.get_context(
+                salt.utils.fopen(template_path).read(),
+                line,
+                marker='    <======================')
+        else:
+            out = '\n{}\n'.format(msg)
+        line = 0
+    return line, out
+
+
 def render_jinja_tmpl(tmplstr, context, tmplpath=None):
     opts = context['opts']
     saltenv = context['saltenv']
@@ -186,13 +260,31 @@ def render_jinja_tmpl(tmplstr, context, tmplpath=None):
     try:
         output = jinja_env.from_string(tmplstr).render(**unicode_context)
     except jinja2.exceptions.TemplateSyntaxError as exc:
-        line = _get_jinja_error_line(traceback.extract_tb(sys.exc_info()[2]))
-        raise SaltRenderError(
-            'Jinja syntax error: {0}'.format(exc), line, tmplstr
-        )
+        trace = traceback.extract_tb(sys.exc_info()[2])
+        line, out = _get_jinja_error(trace, context=unicode_context)
+        if not line:
+            tmplstr = ''
+        raise SaltRenderError('Jinja syntax error: {0}{1}'.format(exc, out),
+                              line,
+                              tmplstr)
     except jinja2.exceptions.UndefinedError as exc:
-        line = _get_jinja_error_line(traceback.extract_tb(sys.exc_info()[2]))
-        raise SaltRenderError('Jinja variable {0}'.format(exc), line, tmplstr)
+        trace = traceback.extract_tb(sys.exc_info()[2])
+        line, out = _get_jinja_error(trace, context=unicode_context)
+        if not line:
+            tmplstr = ''
+        raise SaltRenderError(
+            'Jinja variable {0}{1}'.format(
+                exc, out),
+            line,
+            tmplstr)
+    except Exception, exc:
+        trace = traceback.extract_tb(sys.exc_info()[2])
+        line, out = _get_jinja_error(trace, context=unicode_context)
+        if not line:
+            tmplstr = ''
+        raise SaltRenderError('Jinja error: {0}{1}'.format(exc, out),
+                              line,
+                              tmplstr)
 
     # Workaround a bug in Jinja that removes the final newline
     # (https://github.com/mitsuhiko/jinja2/issues/75)

tests/unit/templates/files/test/hello_import_error

@@ -0,0 +1,2 @@
+{% from 'macroerror' import mymacro -%}
+{{ mymacro('Hey') ~ mymacro(a|default('a'), b|default('b')) }}

tests/unit/templates/files/test/hello_import_generalerror

@@ -0,0 +1,2 @@
+{% from 'macrogeneral' import mymacro -%}
+{{ mymacro() }}

tests/unit/templates/files/test/hello_import_undefined

@@ -0,0 +1,2 @@
+{% from 'macroundefined' import mymacro -%}
+{{ mymacro() }}

tests/unit/templates/files/test/macroerror

@@ -0,0 +1,4 @@
+# macro
+{% macro mymacro(greeting, greetee='world') -} <-- error is here
+{{ greeting ~ ' ' ~ greetee }} !
+{%- endmacro %}

tests/unit/templates/files/test/macrogeneral

@@ -0,0 +1,3 @@
+{% macro mymacro() -%}
+{{ 1/0 }}
+{%- endmacro %}

tests/unit/templates/files/test/macroundefined

@@ -0,0 +1,3 @@
+{% macro mymacro() -%}
+{{b.greetee}} <-- error is here
+{%- endmacro %}

tests/unit/templates/jinja_test.py

@@ -175,6 +175,81 @@ class TestGetTemplate(TestCase):
         self.assertEqual(fc.requests[0]['path'], 'salt://macro')
         SaltCacheLoader.file_client = _fc
 
+    def test_macro_additional_log_for_generalexc(self):
+        '''
+        If we failed in a macro because of eg a typeerror, get
+        more output from trace.
+        '''
+        expected = r'''Jinja error: division by zero
+.*/macrogeneral\(2\):
+---
+\{% macro mymacro\(\) -%\}
+\{\{ 1/0 \}\}    <======================
+\{%- endmacro %\}
+---.*'''
+        filename = os.path.join(TEMPLATES_DIR,
+                                'files', 'test', 'hello_import_generalerror')
+        fc = MockFileClient()
+        _fc = SaltCacheLoader.file_client
+        SaltCacheLoader.file_client = lambda loader: fc
+        self.assertRaisesRegexp(
+            SaltRenderError,
+            expected,
+            render_jinja_tmpl,
+            salt.utils.fopen(filename).read(),
+            dict(opts=self.local_opts, saltenv='other'))
+        SaltCacheLoader.file_client = _fc
+
+    def test_macro_additional_log_for_undefined(self):
+        '''
+        If we failed in a macro because of undefined variables, get
+        more output from trace.
+        '''
+        expected = r'''Jinja variable 'b' is undefined
+.*/macroundefined\(2\):
+---
+\{% macro mymacro\(\) -%\}
+\{\{b.greetee\}\} <-- error is here    <======================
+\{%- endmacro %\}
+---'''
+        filename = os.path.join(TEMPLATES_DIR,
+                                'files', 'test', 'hello_import_undefined')
+        fc = MockFileClient()
+        _fc = SaltCacheLoader.file_client
+        SaltCacheLoader.file_client = lambda loader: fc
+        self.assertRaisesRegexp(
+            SaltRenderError,
+            expected,
+            render_jinja_tmpl,
+            salt.utils.fopen(filename).read(),
+            dict(opts=self.local_opts, saltenv='other'))
+        SaltCacheLoader.file_client = _fc
+
+    def test_macro_additional_log_syntaxerror(self):
+        '''
+        If  we failed in a macro, get more output from trace.
+        '''
+        expected = r'''Jinja syntax error: expected token 'end of statement block', got '-'
+.*/macroerror\(2\):
+---
+# macro
+\{% macro mymacro\(greeting, greetee='world'\) -\} <-- error is here    <======================
+\{\{ greeting ~ ' ' ~ greetee \}\} !
+\{%- endmacro %\}
+---.*'''
+        filename = os.path.join(TEMPLATES_DIR,
+                                'files', 'test', 'hello_import_error')
+        fc = MockFileClient()
+        _fc = SaltCacheLoader.file_client
+        SaltCacheLoader.file_client = lambda loader: fc
+        self.assertRaisesRegexp(
+            SaltRenderError,
+            expected,
+            render_jinja_tmpl,
+            salt.utils.fopen(filename).read(),
+            dict(opts=self.local_opts, saltenv='other'))
+        SaltCacheLoader.file_client = _fc
+
     def test_non_ascii_encoding(self):
         fc = MockFileClient()
         # monkey patch file client