Added EXPLAIN_TEMPLATE_LOADING to help people debug templates not being loaded.

CHANGES

@@ -41,6 +41,9 @@ Version 1.0
   now hardcoded but the default log handling can be disabled through the
   ``LOGGER_HANDLER_POLICY`` configuration key.
 - Removed deprecate module functionality.
+- Added the ``EXPLAIN_TEMPLATE_LOADING`` config flag which when enabled will
+  instruct Flask to explain how it locates templates.  This should help
+  users debug when the wrong templates are loaded.
 
 Version 0.10.2
 --------------

docs/blueprints.rst

@@ -185,6 +185,24 @@ want to render the template ``'admin/index.html'`` and you have provided
 ``templates`` as a `template_folder` you will have to create a file like
 this: ``yourapplication/admin/templates/admin/index.html``.
 
+To further reiterate this: if you have a blueprint named ``admin`` and you
+want to render a template called ``index.html`` which is specific to this
+blueprint, the best idea is to lay out your templates like this::
+
+    yourpackage/
+        blueprints/
+            admin/
+                templates/
+                    admin/
+                        index.html
+                __init__.py
+
+And then when you want to render the template, use ``admin/index.html`` as
+the name to look up the template by.  If you encounter problems loading
+the correct templates enable the ``EXPLAIN_TEMPLATE_LOADING`` config
+variable which will instruct Flask to print out the steps it goes through
+to locate templates on every ``render_template`` call.
+
 Building URLs
 -------------
 

docs/config.rst

@@ -188,6 +188,13 @@ The following configuration values are used internally by Flask:
                                   be viable to disable this feature by setting
                                   this key to ``False``. This option does not
                                   affect debug mode.
+``EXPLAIN_TEMPLATE_LOADING``      If this is enabled then every attempt to
+                                  load a template will write an info
+                                  message to the logger explaining the
+                                  attempts to locate the template.  This
+                                  can be useful to figure out why
+                                  templates cannot be found or wrong
+                                  templates appear to be loaded.
 ================================= =========================================
 
 .. admonition:: More on ``SERVER_NAME``
@@ -234,10 +241,8 @@ The following configuration values are used internally by Flask:
    ``JSON_AS_ASCII``, ``JSON_SORT_KEYS``, ``JSONIFY_PRETTYPRINT_REGULAR``
 
 .. versionadded:: 1.0
-   ``SESSION_REFRESH_EACH_REQUEST``
+   ``SESSION_REFRESH_EACH_REQUEST``, ``TEMPLATES_AUTO_RELOAD``,
-
+   ``LOGGER_HANDLER_POLICY``, ``EXPLAIN_TEMPLATE_LOADING``
-.. versionadded:: 1.0
-   ``TEMPLATES_AUTO_RELOAD``, ``LOGGER_HANDLER_POLICY``
 
 Configuring from Files
 ----------------------

flask/app.py

@@ -292,6 +292,7 @@ class Flask(_PackageBoundObject):
         'SEND_FILE_MAX_AGE_DEFAULT':            12 * 60 * 60, # 12 hours
         'TRAP_BAD_REQUEST_ERRORS':              False,
         'TRAP_HTTP_EXCEPTIONS':                 False,
+        'EXPLAIN_TEMPLATE_LOADING':             False,
         'PREFERRED_URL_SCHEME':                 'http',
         'JSON_AS_ASCII':                        True,
         'JSON_SORT_KEYS':                       True,

flask/debughelpers.py

@@ -8,7 +8,10 @@
     :copyright: (c) 2014 by Armin Ronacher.
     :license: BSD, see LICENSE for more details.
 """
-from ._compat import implements_to_string
+from ._compat import implements_to_string, text_type
+from .app import Flask
+from .blueprints import Blueprint
+from .globals import _request_ctx_stack
 
 
 class UnexpectedUnicodeError(AssertionError, UnicodeError):
@@ -85,3 +88,68 @@ def attach_enctype_error_multidict(request):
     newcls.__name__ = oldcls.__name__
     newcls.__module__ = oldcls.__module__
     request.files.__class__ = newcls
+
+
+def _dump_loader_info(loader):
+    yield 'class: %s.%s' % (type(loader).__module__, type(loader).__name__)
+    for key, value in sorted(loader.__dict__.items()):
+        if key.startswith('_'):
+            continue
+        if isinstance(value, (tuple, list)):
+            if not all(isinstance(x, (str, text_type)) for x in value):
+                continue
+            yield '%s:' % key
+            for item in value:
+                yield '  - %s' % item
+            continue
+        elif not isinstance(value, (str, text_type, int, float, bool)):
+            continue
+        yield '%s: %r' % (key, value)
+
+
+def explain_template_loading_attempts(app, template, attempts):
+    """This should help developers understand what """
+    info = ['Locating template "%s":' % template]
+    total_found = 0
+    blueprint = None
+    reqctx = _request_ctx_stack.top
+    if reqctx is not None and reqctx.request.blueprint is not None:
+        blueprint = reqctx.request.blueprint
+
+    for idx, (loader, srcobj, triple) in enumerate(attempts):
+        if isinstance(srcobj, Flask):
+            src_info = 'application "%s"' % srcobj.import_name
+        elif isinstance(srcobj, Blueprint):
+            src_info = 'blueprint "%s" (%s)' % (srcobj.name,
+                                                srcobj.import_name)
+        else:
+            src_info = repr(srcobj)
+
+        info.append('% 5d: trying loader of %s' % (
+            idx + 1, src_info))
+
+        for line in _dump_loader_info(loader):
+            info.append('       %s' % line)
+
+        if triple is None:
+            detail = 'no match'
+        else:
+            detail = 'found (%r)' % (triple[1] or '<string>')
+            total_found += 1
+        info.append('       -> %s' % detail)
+
+    seems_fishy = False
+    if total_found == 0:
+        info.append('Error: the template could not be found.')
+        seems_fishy = True
+    elif total_found > 1:
+        info.append('Warning: multiple loaders returned a match for the template.')
+        seems_fishy = True
+
+    if blueprint is not None and seems_fishy:
+        info.append('  The template was looked up from an endpoint that '
+                    'belongs to the blueprint "%s".' % blueprint)
+        info.append('  Maybe you did not place a template in the right folder?')
+        info.append('  See http://flask.pocoo.org/docs/blueprints/#templates')
+
+    app.logger.info('\n'.join(info))

flask/sessions.py

@@ -71,6 +71,7 @@ def _tag(value):
         try:
             return text_type(value)
         except UnicodeError:
+            from flask.debughelpers import UnexpectedUnicodeError
             raise UnexpectedUnicodeError(u'A byte string with '
                 u'non-ASCII data was passed to the session system '
                 u'which can only store unicode strings.  Consider '
@@ -362,6 +363,3 @@ class SecureCookieSessionInterface(SessionInterface):
         response.set_cookie(app.session_cookie_name, val,
                             expires=expires, httponly=httponly,
                             domain=domain, path=path, secure=secure)
-
-
-from flask.debughelpers import UnexpectedUnicodeError

flask/templating.py

@@ -8,7 +8,6 @@
     :copyright: (c) 2014 by Armin Ronacher.
     :license: BSD, see LICENSE for more details.
 """
-import posixpath
 from jinja2 import BaseLoader, Environment as BaseEnvironment, \
      TemplateNotFound
 
@@ -54,23 +53,38 @@ class DispatchingJinjaLoader(BaseLoader):
         self.app = app
 
     def get_source(self, environment, template):
-        for loader, local_name in self._iter_loaders(template):
+        explain = self.app.config['EXPLAIN_TEMPLATE_LOADING']
+        attempts = []
+        tmplrv = None
+
+        for srcobj, loader in self._iter_loaders(template):
             try:
-                return loader.get_source(environment, local_name)
+                rv = loader.get_source(environment, template)
+                if tmplrv is None:
+                    tmplrv = rv
+                if not explain:
+                    break
             except TemplateNotFound:
-                pass
+                rv = None
+            attempts.append((loader, srcobj, rv))
+
+        if explain:
+            from debughelpers import explain_template_loading_attempts
+            explain_template_loading_attempts(self.app, template, attempts)
 
+        if tmplrv is not None:
+            return tmplrv
         raise TemplateNotFound(template)
 
     def _iter_loaders(self, template):
         loader = self.app.jinja_loader
         if loader is not None:
-            yield loader, template
+            yield self.app, loader
 
         for blueprint in itervalues(self.app.blueprints):
             loader = blueprint.jinja_loader
             if loader is not None:
-                yield loader, template
+                yield blueprint, loader
 
     def list_templates(self):
         result = set()

flask/testsuite/templating.py

@@ -11,6 +11,9 @@
 
 import flask
 import unittest
+import logging
+from jinja2 import TemplateNotFound
+
 from flask.testsuite import FlaskTestCase
 
 
@@ -303,6 +306,45 @@ class TemplatingTestCase(FlaskTestCase):
         app.config['TEMPLATES_AUTO_RELOAD'] = False
         self.assert_false(app.jinja_env.auto_reload)
 
+    def test_template_loader_debugging(self):
+        from blueprintapp import app
+
+        called = []
+        class _TestHandler(logging.Handler):
+            def handle(x, record):
+                called.append(True)
+                text = unicode(record.msg)
+                self.assert_('1: trying loader of application '
+                             '"blueprintapp"' in text)
+                self.assert_('2: trying loader of blueprint "admin" '
+                             '(blueprintapp.apps.admin)' in text)
+                self.assert_('trying loader of blueprint "frontend" '
+                             '(blueprintapp.apps.frontend)' in text)
+                self.assert_('Error: the template could not be found' in text)
+                self.assert_('looked up from an endpoint that belongs to '
+                             'the blueprint "frontend"' in text)
+                self.assert_(
+                    'See http://flask.pocoo.org/docs/blueprints/#templates' in text)
+
+        with app.test_client() as c:
+            try:
+                old_load_setting = app.config['EXPLAIN_TEMPLATE_LOADING']
+                old_handlers = app.logger.handlers[:]
+                app.logger.handlers = [_TestHandler()]
+                app.config['EXPLAIN_TEMPLATE_LOADING'] = True
+
+                try:
+                    c.get('/missing')
+                except TemplateNotFound as e:
+                    self.assert_('missing_template.html' in str(e))
+                else:
+                    self.fail('Expected template not found exception.')
+            finally:
+                app.logger.handlers[:] = old_handlers
+                app.config['EXPLAIN_TEMPLATE_LOADING'] = old_load_setting
+
+        self.assert_equal(len(called), 1)
+
 
 def suite():
     suite = unittest.TestSuite()

flask/testsuite/test_apps/blueprintapp/__init__.py

@@ -1,6 +1,7 @@
 from flask import Flask
 
 app = Flask(__name__)
+app.config['DEBUG'] = True
 from blueprintapp.apps.admin import admin
 from blueprintapp.apps.frontend import frontend
 app.register_blueprint(admin)

flask/testsuite/test_apps/blueprintapp/apps/frontend/__init__.py

@@ -6,3 +6,8 @@ frontend = Blueprint('frontend', __name__, template_folder='templates')
 @frontend.route('/')
 def index():
     return render_template('frontend/index.html')
+
+
+@frontend.route('/missing')
+def missing_template():
+    return render_template('missing_template.html')

flask/wrappers.py

@@ -12,7 +12,6 @@
 from werkzeug.wrappers import Request as RequestBase, Response as ResponseBase
 from werkzeug.exceptions import BadRequest
 
-from .debughelpers import attach_enctype_error_multidict
 from . import json
 from .globals import _request_ctx_stack
 
@@ -184,6 +183,7 @@ class Request(RequestBase):
         ctx = _request_ctx_stack.top
         if ctx is not None and ctx.app.debug and \
            self.mimetype != 'multipart/form-data' and not self.files:
+            from .debughelpers import attach_enctype_error_multidict
             attach_enctype_error_multidict(self)