Improve warnings on undefined template errors (#48713)

homeassistant/helpers/template.py

@@ -6,6 +6,7 @@ import asyncio
 import base64
 import collections.abc
 from contextlib import suppress
+from contextvars import ContextVar
 from datetime import datetime, timedelta
 from functools import partial, wraps
 import json
@@ -79,6 +80,8 @@ _COLLECTABLE_STATE_ATTRIBUTES = {
 ALL_STATES_RATE_LIMIT = timedelta(minutes=1)
 DOMAIN_STATES_RATE_LIMIT = timedelta(seconds=1)
 
+template_cv: ContextVar[str | None] = ContextVar("template_cv", default=None)
+
 
 @bind_hass
 def attach(hass: HomeAssistant, obj: Any) -> None:
@@ -299,7 +302,7 @@ class Template:
 
         self.template: str = template.strip()
         self._compiled_code = None
-        self._compiled: Template | None = None
+        self._compiled: jinja2.Template | None = None
         self.hass = hass
         self.is_static = not is_template_string(template)
         self._limited = None
@@ -370,7 +373,7 @@ class Template:
             kwargs.update(variables)
 
         try:
-            render_result = compiled.render(kwargs)
+            render_result = _render_with_context(self.template, compiled, **kwargs)
         except Exception as err:
             raise TemplateError(err) from err
 
@@ -442,7 +445,7 @@ class Template:
 
         def _render_template() -> None:
             try:
-                compiled.render(kwargs)
+                _render_with_context(self.template, compiled, **kwargs)
             except TimeoutError:
                 pass
             finally:
@@ -524,7 +527,9 @@ class Template:
             variables["value_json"] = json.loads(value)
 
         try:
-            return self._compiled.render(variables).strip()
+            return _render_with_context(
+                self.template, self._compiled, **variables
+            ).strip()
         except jinja2.TemplateError as ex:
             if error_value is _SENTINEL:
                 _LOGGER.error(
@@ -535,7 +540,7 @@ class Template:
                 )
             return value if error_value is _SENTINEL else error_value
 
-    def _ensure_compiled(self, limited: bool = False) -> Template:
+    def _ensure_compiled(self, limited: bool = False) -> jinja2.Template:
         """Bind a template to a specific hass instance."""
         self.ensure_valid()
 
@@ -548,7 +553,7 @@ class Template:
         env = self._env
 
         self._compiled = cast(
-            Template,
+            jinja2.Template,
             jinja2.Template.from_code(env, self._compiled_code, env.globals, None),
         )
 
@@ -1314,12 +1319,59 @@ def urlencode(value):
     return urllib_urlencode(value).encode("utf-8")
 
 
+def _render_with_context(
+    template_str: str, template: jinja2.Template, **kwargs: Any
+) -> str:
+    """Store template being rendered in a ContextVar to aid error handling."""
+    template_cv.set(template_str)
+    return template.render(**kwargs)
+
+
+class LoggingUndefined(jinja2.Undefined):
+    """Log on undefined variables."""
+
+    def _log_message(self):
+        template = template_cv.get() or ""
+        _LOGGER.warning(
+            "Template variable warning: %s when rendering '%s'",
+            self._undefined_message,
+            template,
+        )
+
+    def _fail_with_undefined_error(self, *args, **kwargs):
+        try:
+            return super()._fail_with_undefined_error(*args, **kwargs)
+        except self._undefined_exception as ex:
+            template = template_cv.get() or ""
+            _LOGGER.error(
+                "Template variable error: %s when rendering '%s'",
+                self._undefined_message,
+                template,
+            )
+            raise ex
+
+    def __str__(self):
+        """Log undefined __str___."""
+        self._log_message()
+        return super().__str__()
+
+    def __iter__(self):
+        """Log undefined __iter___."""
+        self._log_message()
+        return super().__iter__()
+
+    def __bool__(self):
+        """Log undefined __bool___."""
+        self._log_message()
+        return super().__bool__()
+
+
 class TemplateEnvironment(ImmutableSandboxedEnvironment):
     """The Home Assistant template environment."""
 
     def __init__(self, hass, limited=False):
         """Initialise template environment."""
-        super().__init__(undefined=jinja2.make_logging_undefined(logger=_LOGGER))
+        super().__init__(undefined=LoggingUndefined)
         self.hass = hass
         self.template_cache = weakref.WeakValueDictionary()
         self.filters["round"] = forgiving_round

tests/helpers/test_template.py

@@ -2503,4 +2503,7 @@ async def test_undefined_variable(hass, caplog):
     """Test a warning is logged on undefined variables."""
     tpl = template.Template("{{ no_such_variable }}", hass)
     assert tpl.async_render() == ""
-    assert "Template variable warning: no_such_variable is undefined" in caplog.text
+    assert (
+        "Template variable warning: 'no_such_variable' is undefined when rendering '{{ no_such_variable }}'"
+        in caplog.text
+    )