feat(jinja): better jinja feedback and error catching (#4629)

When an error is encountered while trying to parse a jinja template,
the traceback is automatically parsed to get the specific error and
the line number that caused this error, and then this information is
turned into a user-friendly single-line error message.

The cloud-init runtime will log these error messages when jinja
syntax errors are encountered in the cloud-config file. For the
query, render, and schema commands, the nasty traceback is caught
and a single line error message is given to the user instead.

Fixes GH-4360

cloudinit/cmd/devel/render.py

@@ -12,6 +12,7 @@
 from cloudinit.cmd.devel import read_cfg_paths
 from cloudinit.handlers.jinja_template import (
     JinjaLoadError,
+    JinjaSyntaxParsingException,
     NotJinjaError,
     render_jinja_payload_from_file,
 )
@@ -99,6 +100,13 @@ def render_template(user_data_path, instance_data_path=None, debug=False):
             "Cannot render from instance data due to exception: %s", repr(e)
         )
         return 1
+    except JinjaSyntaxParsingException as e:
+        LOG.error(
+            "Failed to render templated user-data file '%s'. %s",
+            user_data_path,
+            str(e),
+        )
+        return 1
     if not rendered_payload:
         LOG.error("Unable to render user-data file: %s", user_data_path)
         return 1

cloudinit/cmd/query.py

@@ -29,6 +29,7 @@
     render_jinja_payload,
 )
 from cloudinit.sources import REDACT_SENSITIVE_VALUE
+from cloudinit.templater import JinjaSyntaxParsingException
 
 NAME = "query"
 LOG = logging.getLogger(__name__)
@@ -277,12 +278,19 @@ def handle_args(name, args):
         return 1
     if args.format:
         payload = "## template: jinja\n{fmt}".format(fmt=args.format)
-        rendered_payload = render_jinja_payload(
-            payload=payload,
-            payload_fn="query commandline",
-            instance_data=instance_data,
-            debug=True if args.debug else False,
-        )
+        try:
+            rendered_payload = render_jinja_payload(
+                payload=payload,
+                payload_fn="query commandline",
+                instance_data=instance_data,
+                debug=True if args.debug else False,
+            )
+        except JinjaSyntaxParsingException as e:
+            LOG.error(
+                "Failed to render templated data. %s",
+                str(e),
+            )
+            return 1
         if rendered_payload:
             print(rendered_payload)
             return 0

cloudinit/config/cc_final_message.py

@@ -96,6 +96,10 @@ def handle(name: str, cfg: Config, cloud: Cloud, args: list) -> None:
             stderr=True,
             log=LOG,
         )
+    except templater.JinjaSyntaxParsingException as e:
+        util.logexc(
+            LOG, "Failed to render templated final message: %s", str(e)
+        )
     except Exception:
         util.logexc(LOG, "Failed to render final message template")
 

cloudinit/config/schema.py

@@ -816,9 +816,12 @@ def _get_config_type_and_rendered_userdata(
     :return: UserDataTypeAndDecodedContent
     :raises: SchemaValidationError when non-jinja content found but
         header declared ## template: jinja.
+    :raises JinjaSyntaxParsingException when jinja syntax error found.
+    :raises JinjaLoadError when jinja template fails to load.
     """
     from cloudinit.handlers.jinja_template import (
         JinjaLoadError,
+        JinjaSyntaxParsingException,
         NotJinjaError,
         render_jinja_payload_from_file,
     )
@@ -840,6 +843,11 @@ def _get_config_type_and_rendered_userdata(
                     )
                 ]
             ) from e
+        except JinjaSyntaxParsingException as e:
+            error(
+                "Failed to render templated user-data. " + str(e),
+                sys_exit=True,
+            )
         except JinjaLoadError as e:
             error(str(e), sys_exit=True)
         schema_position = "format-l2.c1"

cloudinit/handlers/jinja_template.py

@@ -13,6 +13,7 @@
 from cloudinit.settings import PER_ALWAYS
 from cloudinit.templater import (
     MISSING_JINJA_PREFIX,
+    JinjaSyntaxParsingException,
     detect_template,
     render_string,
 )
@@ -54,9 +55,19 @@ def handle_part(self, data, ctype, filename, payload, frequency, headers):
         if ctype in handlers.CONTENT_SIGNALS:
             return
         jinja_json_file = self.paths.get_runpath("instance_data_sensitive")
-        rendered_payload = render_jinja_payload_from_file(
-            payload, filename, jinja_json_file
-        )
+        try:
+            rendered_payload = render_jinja_payload_from_file(
+                payload, filename, jinja_json_file
+            )
+        except JinjaSyntaxParsingException as e:
+            LOG.warning(
+                "Ignoring jinja template for %s. "
+                "Failed to render template. %s",
+                filename,
+                str(e),
+            )
+            return
+
         if not rendered_payload:
             return
         subtype = handlers.type_from_starts_with(rendered_payload)

cloudinit/templater.py

@@ -18,6 +18,8 @@
 import sys
 from typing import Any
 
+from jinja2 import TemplateSyntaxError
+
 from cloudinit import type_utils as tu
 from cloudinit import util
 from cloudinit.atomic_helper import write_file
@@ -42,6 +44,47 @@
 MISSING_JINJA_PREFIX = "CI_MISSING_JINJA_VAR/"
 
 
+class JinjaSyntaxParsingException(TemplateSyntaxError):
+    def __init__(
+        self,
+        error: TemplateSyntaxError,
+    ) -> None:
+        super().__init__(
+            error.message or "unknown syntax error",
+            error.lineno,
+            error.name,
+            error.filename,
+        )
+        self.source = error.source
+
+    def __str__(self):
+        """Avoid jinja2.TemplateSyntaxErrror multi-line __str__ format."""
+        return self.format_error_message(
+            syntax_error=self.message,
+            line_number=self.lineno,
+            line_content=self.source.splitlines()[self.lineno - 2].strip(),
+        )
+
+    @staticmethod
+    def format_error_message(
+        syntax_error: str,
+        line_number: str,
+        line_content: str = "",
+    ) -> str:
+        """Avoid jinja2.TemplateSyntaxErrror multi-line __str__ format."""
+        line_content = f": {line_content}" if line_content else ""
+        return JinjaSyntaxParsingException.message_template.format(
+            syntax_error=syntax_error,
+            line_number=line_number,
+            line_content=line_content,
+        )
+
+    message_template = (
+        "Unable to parse Jinja template due to syntax error: "
+        "{syntax_error} on line {line_number}{line_content}"
+    )
+
+
 # Mypy, and the PEP 484 ecosystem in general, does not support creating
 # classes with dynamic base types: https://stackoverflow.com/a/59636248
 class UndefinedJinjaVariable(JUndefined):
@@ -102,18 +145,27 @@ def detect_template(text):
     def jinja_render(content, params):
         # keep_trailing_newline is in jinja2 2.7+, not 2.6
         add = "\n" if content.endswith("\n") else ""
-        return (
-            JTemplate(
-                content,
-                undefined=UndefinedJinjaVariable,
-                trim_blocks=True,
-                extensions=["jinja2.ext.do"],
-            ).render(**params)
-            + add
-        )
+        try:
+            return (
+                JTemplate(
+                    content,
+                    undefined=UndefinedJinjaVariable,
+                    trim_blocks=True,
+                    extensions=["jinja2.ext.do"],
+                ).render(**params)
+                + add
+            )
+        except TemplateSyntaxError as template_syntax_error:
+            template_syntax_error.lineno += 1
+            raise JinjaSyntaxParsingException(
+                error=template_syntax_error,
+                # source=content,
+            ) from template_syntax_error
+        except Exception as unknown_error:
+            raise unknown_error from unknown_error
 
     if text.find("\n") != -1:
-        ident, rest = text.split("\n", 1)
+        ident, rest = text.split("\n", 1)  # remove the first line
     else:
         ident = text
         rest = ""

cloudinit/util.py

@@ -303,6 +303,7 @@ def read_conf(fname, *, instance_data_file=None) -> Dict:
     # Avoid circular import
     from cloudinit.handlers.jinja_template import (
         JinjaLoadError,
+        JinjaSyntaxParsingException,
         NotJinjaError,
         render_jinja_payload_from_file,
     )
@@ -328,6 +329,12 @@ def read_conf(fname, *, instance_data_file=None) -> Dict:
                 instance_data_file,
                 fname,
             )
+        except JinjaSyntaxParsingException as e:
+            LOG.warning(
+                "Failed to render templated yaml config file '%s'. %s",
+                fname,
+                e,
+            )
         except NotJinjaError:
             # A log isn't appropriate here as we generally expect most
             # cloud.cfgs to not be templated. The other path is logged

tests/unittests/cmd/devel/test_render.py

@@ -6,6 +6,7 @@
 
 from cloudinit.cmd.devel import render
 from cloudinit.helpers import Paths
+from cloudinit.templater import JinjaSyntaxParsingException
 from cloudinit.util import ensure_dir, write_file
 from tests.unittests.helpers import mock, skipUnlessJinja
 
@@ -148,3 +149,19 @@ def test_no_user_data(self, caplog, tmpdir):
         write_file(instance_data, '{"my-var": "jinja worked"}')
         render.render_template(user_data, instance_data, False)
         assert "Unable to render user-data file" in caplog.text
+
+    @skipUnlessJinja()
+    def test_invalid_jinja_syntax(self, caplog, tmpdir):
+        user_data = tmpdir.join("user-data")
+        write_file(user_data, "##template: jinja\nrendering: {{ my_var } }")
+        instance_data = tmpdir.join("instance-data")
+        write_file(instance_data, '{"my-var": "jinja worked"}')
+        assert render.render_template(user_data, instance_data, True) == 1
+        assert (
+            JinjaSyntaxParsingException.format_error_message(
+                syntax_error="unexpected '}'",
+                line_number=2,
+                line_content="rendering: {{ my_var } }",
+            )
+            in caplog.text
+        )

tests/unittests/cmd/test_query.py

@@ -15,6 +15,7 @@
 from cloudinit.cmd import query
 from cloudinit.helpers import Paths
 from cloudinit.sources import REDACT_SENSITIVE_VALUE
+from cloudinit.templater import JinjaSyntaxParsingException
 from cloudinit.util import write_file
 from tests.unittests.helpers import mock
 
@@ -567,3 +568,67 @@ def test_handle_args_list_keys_errors_when_varname_is_not_a_dict(
             m_getuid.return_value = 100
             assert 1 == query.handle_args("anyname", args)
         assert expected_error in caplog.text
+
+    @pytest.mark.parametrize(
+        "header_included",
+        [True, False],
+    )
+    def test_handle_args_formats_jinja_successfully(
+        self, caplog, tmpdir, capsys, header_included
+    ):
+        """Test that rendering a jinja template works as expected."""
+        instance_data = tmpdir.join("instance-data")
+        instance_data.write(
+            '{"v1": {"v1_1": "val1.1", "v1_2": "val1.2"}, "v2": '
+            '{"v2_2": "val2.2"}, "top": "gun"}'
+        )
+        header = "## template: jinja\n" if header_included else ""
+        format = header + "v1_1: {{ v1.v1_1 }}"
+        expected = header + "v1_1: val1.1\n"
+
+        args = self.Args(
+            debug=False,
+            dump_all=False,
+            format=format,
+            instance_data=instance_data.strpath,
+            list_keys=False,
+            user_data="ud",
+            vendor_data="vd",
+            varname=None,
+        )
+        with mock.patch("os.getuid") as m_getuid:
+            m_getuid.return_value = 100
+            assert 0 == query.handle_args("anyname", args)
+        out, _err = capsys.readouterr()
+        assert expected == out
+
+    def test_handle_args_invalid_jinja_exception(self, caplog, tmpdir, capsys):
+        """Raise an error when a jinja syntax error is encountered."""
+        instance_data = tmpdir.join("instance-data")
+        instance_data.write(
+            '{"v1": {"v1_1": "val1.1", "v1_2": "val1.2"}, "v2": '
+            '{"v2_2": "val2.2"}, "top": "gun"}'
+        )
+        format = "v1_1: {{ v1.v1_1 } }"
+        expected_error = (
+            "Failed to render templated data. "
+            + JinjaSyntaxParsingException.format_error_message(
+                syntax_error="unexpected '}'",
+                line_number=2,
+                line_content="v1_1: {{ v1.v1_1 } }",
+            )
+        )
+        args = self.Args(
+            debug=False,
+            dump_all=False,
+            format=format,
+            instance_data=instance_data.strpath,
+            list_keys=False,
+            user_data="ud",
+            vendor_data="vd",
+            varname=None,
+        )
+        with mock.patch("os.getuid") as m_getuid:
+            m_getuid.return_value = 100
+            assert 1 == query.handle_args("anyname", args)
+        assert expected_error in caplog.text

tests/unittests/config/test_schema.py

@@ -40,6 +40,7 @@
 from cloudinit.safeyaml import load, load_with_marks
 from cloudinit.settings import FREQUENCIES
 from cloudinit.sources import DataSourceNotFoundException
+from cloudinit.templater import JinjaSyntaxParsingException
 from cloudinit.util import load_file, write_file
 from tests.hypothesis import given
 from tests.hypothesis_jsonschema import from_schema
@@ -825,6 +826,41 @@ def test_validateconfig_file_no_cloud_cfg(
             " Nothing to validate" in out
         )
 
+    @pytest.mark.parametrize("annotate", (True, False))
+    def test_validateconfig_file_raises_jinja_syntax_error(
+        self, annotate, tmpdir, mocker, capsys
+    ):
+        """ """
+        # will throw error because of space between last two }'s
+        invalid_jinja_template = "## template: jinja\na:b\nc:{{ d } }"
+        mocker.patch("os.path.exists", return_value=True)
+        mocker.patch(
+            "cloudinit.util.load_file",
+            return_value=invalid_jinja_template,
+        )
+        mocker.patch(
+            "cloudinit.handlers.jinja_template.load_file",
+            return_value='{"c": "d"}',
+        )
+        config_file = tmpdir.join("my.yaml")
+        config_file.write(invalid_jinja_template)
+        with pytest.raises(SystemExit) as context_manager:
+            validate_cloudconfig_file(config_file.strpath, {}, annotate)
+        assert 1 == context_manager.value.code
+
+        _out, err = capsys.readouterr()
+        expected = (
+            "Error:\n"
+            "Failed to render templated user-data. "
+            + JinjaSyntaxParsingException.format_error_message(
+                syntax_error="unexpected '}'",
+                line_number=3,
+                line_content="c:{{ d } }",
+            )
+            + "\n"
+        )
+        assert expected == err
+
 
 class TestSchemaDocMarkdown:
     """Tests for get_meta_doc."""