From 392f64842f678b6e29a2e5fac65a586d9c9a57ff Mon Sep 17 00:00:00 2001 From: Nick Johnson Date: Fri, 11 Sep 2015 16:35:21 -0700 Subject: [PATCH] Fixed #25373 -- Added warning logging for exceptions during {% include %} tag rendering. --- django/template/loader_tags.py | 10 ++++++ docs/ref/templates/builtins.txt | 11 ++++-- docs/releases/1.9.txt | 11 ++++-- tests/template_tests/test_logging.py | 51 ++++++++++++++++++++++++++-- 4 files changed, 75 insertions(+), 8 deletions(-) diff --git a/django/template/loader_tags.py b/django/template/loader_tags.py index 1d6d922ede..e491a25cbb 100644 --- a/django/template/loader_tags.py +++ b/django/template/loader_tags.py @@ -1,3 +1,4 @@ +import logging from collections import defaultdict from django.utils import six @@ -12,6 +13,8 @@ register = Library() BLOCK_CONTEXT_KEY = 'block_context' +logger = logging.getLogger('django.template') + class ExtendsError(Exception): pass @@ -207,6 +210,13 @@ class IncludeNode(Node): except Exception: if context.template.engine.debug: raise + template_name = getattr(context, 'template_name', None) or 'unknown' + logger.warn( + "Exception raised while rendering {%% include %%} for " + "template '%s'. Empty string rendered instead.", + template_name, + exc_info=True, + ) return '' diff --git a/docs/ref/templates/builtins.txt b/docs/ref/templates/builtins.txt index 1c5840d508..d032d7b1cc 100644 --- a/docs/ref/templates/builtins.txt +++ b/docs/ref/templates/builtins.txt @@ -673,9 +673,14 @@ if it's missing or has syntax errors), the behavior varies depending on the :class:`template engine's ` ``debug`` option (if not set, this option defaults to the value of :setting:`DEBUG`). When debug mode is turned on, an exception like :exc:`~django.template.TemplateDoesNotExist` or -:exc:`~django.template.TemplateSyntaxError` will be raised; otherwise -``{% include %}`` silences any exception that happens while rendering the -included template and returns an empty string. +:exc:`~django.template.TemplateSyntaxError` will be raised. When debug mode +is turned off, ``{% include %}`` logs a warning to the ``django.template`` +logger with the exception that happens while rendering the included template +and returns an empty string. + +.. versionchanged:: 1.9 + + Template logging now includes the warning logging mentioned above. .. note:: The :ttag:`include` tag should be considered as an implementation of diff --git a/docs/releases/1.9.txt b/docs/releases/1.9.txt index 0bb1523f57..bc30395b13 100644 --- a/docs/releases/1.9.txt +++ b/docs/releases/1.9.txt @@ -596,8 +596,15 @@ Templates * Added a :meth:`Context.setdefault() ` method. -* A warning will now be logged for missing context variables. These messages - will be logged to the :ref:`django.template ` logger. +* The :ref:`django.template ` logger was added and + includes the following messages: + + * A ``DEBUG`` level message for missing context variables. + + * A ``WARNING`` level message for uncaught exceptions raised + during the rendering of an ``{% include %}`` when debug mode is off + (helpful since ``{% include %}`` silences the exception and returns an + empty string). * The :ttag:`firstof` template tag supports storing the output in a variable using 'as'. diff --git a/tests/template_tests/test_logging.py b/tests/template_tests/test_logging.py index 4b47abd289..c231fb28d6 100644 --- a/tests/template_tests/test_logging.py +++ b/tests/template_tests/test_logging.py @@ -2,7 +2,7 @@ from __future__ import unicode_literals import logging -from django.template import Engine, Variable, VariableDoesNotExist +from django.template import Context, Engine, Variable, VariableDoesNotExist from django.test import SimpleTestCase @@ -15,18 +15,22 @@ class TestHandler(logging.Handler): self.log_record = record -class VariableResolveLoggingTests(SimpleTestCase): +class BaseTemplateLoggingTestCase(SimpleTestCase): def setUp(self): self.test_handler = TestHandler() self.logger = logging.getLogger('django.template') self.original_level = self.logger.level self.logger.addHandler(self.test_handler) - self.logger.setLevel(logging.DEBUG) + self.logger.setLevel(self.loglevel) def tearDown(self): self.logger.removeHandler(self.test_handler) self.logger.level = self.original_level + +class VariableResolveLoggingTests(BaseTemplateLoggingTestCase): + loglevel = logging.DEBUG + def test_log_on_variable_does_not_exist_silent(self): class TestObject(object): class SilentDoesNotExist(Exception): @@ -78,3 +82,44 @@ class VariableResolveLoggingTests(SimpleTestCase): def test_no_log_when_variable_exists(self): Variable('article.section').resolve({'article': {'section': 'News'}}) self.assertIsNone(self.test_handler.log_record) + + +class IncludeNodeLoggingTests(BaseTemplateLoggingTestCase): + loglevel = logging.WARN + + @classmethod + def setUpClass(cls): + super(IncludeNodeLoggingTests, cls).setUpClass() + cls.engine = Engine(loaders=[ + ('django.template.loaders.locmem.Loader', { + 'child': '{{ raises_exception }}', + }), + ], debug=False) + + def error_method(): + raise IndexError("some generic exception") + + cls.ctx = Context({'raises_exception': error_method}) + + def test_logs_exceptions_during_rendering_with_debug_disabled(self): + template = self.engine.from_string('{% include "child" %}') + template.name = 'template_name' + self.assertEqual(template.render(self.ctx), '') + self.assertEqual( + self.test_handler.log_record.getMessage(), + "Exception raised while rendering {% include %} for template " + "'template_name'. Empty string rendered instead." + ) + self.assertIsNotNone(self.test_handler.log_record.exc_info) + self.assertEqual(self.test_handler.log_record.levelno, logging.WARN) + + def test_logs_exceptions_during_rendering_with_no_template_name(self): + template = self.engine.from_string('{% include "child" %}') + self.assertEqual(template.render(self.ctx), '') + self.assertEqual( + self.test_handler.log_record.getMessage(), + "Exception raised while rendering {% include %} for template " + "'unknown'. Empty string rendered instead." + ) + self.assertIsNotNone(self.test_handler.log_record.exc_info) + self.assertEqual(self.test_handler.log_record.levelno, logging.WARN)